icecream icon indicating copy to clipboard operation
icecream copied to clipboard

print() is 68 times faster than ic()

Open offchan42 opened this issue 6 years ago • 18 comments

Try the following code to test speed of print() vs ic():

from icecream import ic
from time import time

start = time()
for i in range(1000):
    print("i:", i)
stop = time()
elapsed = stop - start

start = time()
for i in range(1000):
    ic(i)
stop = time()
elapsed2 = stop - start

print(elapsed)
print(elapsed2)
print(f"print() is {elapsed2 / elapsed} times faster than ic()")

I found that print is 68 times faster! image

How to make it faster? Why is it so slow? Is it because of the coloring?

offchan42 avatar Sep 27 '19 02:09 offchan42

Finding where ic was called from is a very complicated operation, Python doesn't offer it for free. I'm surprised the difference isn't bigger. In fact you call print 100 times but ic 1000 times, which suggests ic is just 6.8 times faster. If you replace print with sys.stdout.write you might get a fairer comparison.

#33 should make repeated calls faster.

alexmojaki avatar Sep 27 '19 05:09 alexmojaki

Sorry about the 100 times vs 1000 times. The elapsed time is actually correct, I just put in wrong code. I've changed it now to 1000 vs 1000. So it's still 68 times faster using print. If I set print to 100 times then the difference will be bigger. Note for future reader: You won't see 100 because I already modified the code to 1000. For you, the code is correct, so skip this comment.

offchan42 avatar Sep 28 '19 02:09 offchan42

Is ic()'s performance presenting a problem? If so, how and where?

IceCream is a debugging library and thus should not be performance-critical (eg used in a tight loop in production). As @alexmojaki mentioned, ic() does a lot of work to determine output (open source files, parse Python code, etc).

If you want to dive in to improve IceCream's performance, I'd ebulliently welcome and merge such PRs. But performance is not my focus with IceCream until it presents itself as a problem.

As for tight loops and/or production, the forthcoming #33 (also a huge thanks to @alexmojaki there) will help.

gruns avatar Sep 30 '19 20:09 gruns

When I was interacting with UI elements and the UI will report some number in the command line. E.g. dragging a slider and then it computes something. The ic() will make the slider look unresponsive if you move the slider passes through many callback points quickly (like from 0 to 100). But it is fine in that case I change to use print(). It would be better though if I can use ic there.

offchan42 avatar Sep 30 '19 21:09 offchan42

Aha. That would do it. Great example of an ic() use case where performance matters.

A threaded implementation would solve this. Do all ic() work in a non-UI thread, eg via the threading library. File I/O is requisite for ic(), and there's no easy way to speed that up.

Is this something you could tackle?

gruns avatar Sep 30 '19 21:09 gruns

No. I don't know threading in python yet.

offchan42 avatar Oct 01 '19 00:10 offchan42

Try using the pp function in snoop.

alexmojaki avatar Oct 01 '19 06:10 alexmojaki

I see that snoop seems to be more intense in its number of features, providing more options than ic. Though ic is simple and easy to get started. I tried using snoop and it looks good. Do you suggest me to try pp function because you think it's faster?

offchan42 avatar Oct 02 '19 05:10 offchan42

Yes, pp uses executing which is more accurate than ic and has caching which makes it much faster over many calls. #33 is to bring the same functionality to icecream.

Using pp should be the same experience as using ic. The rest of snoop is also great but serves different purposes.

alexmojaki avatar Oct 02 '19 05:10 alexmojaki

@alexmojaki Yes. I tried experimenting with this code

from time import time

from icecream import ic
from snoop import pp


def process(print_func, n_iter):
    start = time()
    for i in range(n_iter):
        print_func(i)
    stop = time()
    elapsed = stop - start
    return elapsed


n_iter = 10_000
e1 = process(lambda i: print("i:", i), n_iter)
e2 = process(ic, n_iter)
e3 = process(pp, n_iter)

print("print elapsed:", e1)
print("ic elapsed:", e2)
print("pp elapsed:", e3)
print(f"print() is {e2 / e1} times faster than ic()")
print(f"print() is {e3 / e1} times faster than pp()")

And here is the result:

print elapsed: 0.5972144603729248
ic elapsed: 43.248204708099365
pp elapsed: 3.786238431930542
print() is 72.41653974870843 times faster than ic()
print() is 6.339830468214487 times faster than pp()

So yeah, pp is definitely faster than ic! I don't know why I would not use it. You need a more catchy naming of the library and that's it. Also it doesn't have the issue I mentioned here: #35 It looks to me that it's better in every way, as of now. image It should print within one line though if the print can fit in one line.

offchan42 avatar Oct 02 '19 05:10 offchan42

After testing both pp and ic, I've found that pp works better in cmd, but ic is better in jupyter lab. image See that pp does not report the argument name. It only reports the argument name if it's inside a function. And I like the one line style more.

offchan42 avatar Oct 06 '19 10:10 offchan42

Thanks for pointing this out to me. IPython does some extra magic which makes it harder for executing to know that everything is working OK. If you pip install -U executing you should find that pp works again.

alexmojaki avatar Oct 06 '19 12:10 alexmojaki

It seems you know what you doing! image

offchan42 avatar Oct 06 '19 18:10 offchan42

I will close this issue for now as it seems like I can get around with slowness issue by using pp. I think improving speed of ic will need some significant core upgrades, so better leave it as is now.

offchan42 avatar Oct 06 '19 18:10 offchan42

After testing both pp and ic, I've found that pp works better in cmd, but ic is better in jupyter lab. image See that pp does not report the argument name. It only reports the argument name if it's inside a function. And I like the one line style more.

I don't know it's due to the problem from VSCode or somewhere else using ic to print something is literally much more slower (like print character by character) in jupyter in VSCode (remote) But pprint works fine. also ic works fine on jupyter in browser

matthewdm0816 avatar Jun 26 '21 10:06 matthewdm0816

using ic to print something is literally much more slower (like print character by character)

this sounds like an issue, perhaps, outside icecream. behind the scenes icecream just calls print() itself:

def stderrPrint(*args):
    print(*args, file=sys.stderr)
  • https://github.com/gruns/icecream/blob/master/icecream/icecream.py#L68

can you

  1. record a video of the behavior so we can see exactly what you see

and

  1. try printing to stdout directly with
ic.configureOutput(outputFunction=print)

is the same character by character delay seen?

gruns avatar Jun 27 '21 20:06 gruns

using ic to print something is literally much more slower (like print character by character)

this sounds like an issue, perhaps, outside icecream. behind the scene's icecream just calls print() itself:

def stderrPrint(*args):
    print(*args, file=sys.stderr)
  • https://github.com/gruns/icecream/blob/master/icecream/icecream.py#L68

can you

  1. record a video of the behavior so we can see exactly what you see

and

  1. try printing to stdout directly with
ic.configureOutput(outputFunction=print)

is the same character by character delay seen?

Not niche issue. On VSCode, using this configuration is sooooo fast and really useful!

mikeseven avatar Aug 17 '21 19:08 mikeseven

On VSCode, using this configuration is sooooo fast and really useful!

to be explicit, using this configuration

ic.configureOutput(outputFunction=print)

right?

gruns avatar Aug 18 '21 19:08 gruns