Uh oh!
There was an error while loading.Please reload this page.
- Notifications
You must be signed in to change notification settings - Fork33.7k
Description
Bug report
Bug description:
(FromDiscourse)
Consider these two functions:
defshort():try:if0==1:unreachedraiseRuntimeErrorexceptRuntimeError:passdeflong():try:if0==1:unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedraiseRuntimeErrorexceptRuntimeError:pass
The only difference is thatlong() has 100 unreached statements instead of just one. But it takes much longer in Python 3.11 (and a bit longer in Python 3.10). Times from@jamestwebber (here):
Python: 3.11.5 | packaged by conda-forge | (main, Aug 27 2023, 03:34:09) [GCC 12.3.0] 176.5 ± 0.4 ns short 644.7 ± 0.6 ns longPython: 3.10.12 | packaged by conda-forge | (main, Jun 23 2023, 22:40:32) [GCC 12.3.0] 150.7 ± 0.1 ns short 167.0 ± 0.2 ns longWhy? Shouldn't it just jump over them all and be just as fast asshort()?
Benchmark script
fromtimeitimporttimeitfromtimeimportperf_counterastimefromstatisticsimportmean,stdevimportsysdefshort():try:if0==1:unreachedraiseRuntimeErrorexceptRuntimeError:passdeflong():try:if0==1:unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedunreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreached;unreachedraiseRuntimeErrorexceptRuntimeError:passfuncs=short,longfor_inrange(3):times= {f: []forfinfuncs}defstats(f):ts= [t*1e9fortinsorted(times[f])[:5]]returnf'{mean(ts):6.1f} ±{stdev(ts):4.1f} ns 'for_inrange(100):forfinfuncs:t=timeit(f,number=10**4)/1e4times[f].append(t)forfinsorted(funcs,key=stats):print(stats(f),f.__name__)print()print('Python:',sys.version)
In fact it takes time linear in how many unreached statements there are. Times for 100 to 100000 unreached statements (on one line, before thetry):
100 2.6 μs 1000 24.3 μs 10000 253.3 μs100000 2786.2 μsBenchmark script
fromtimeimportperf_counterastimefromtimeitimportrepeatforeinrange(2,6):n=10**eexec(f'''def f(): if 0 == 1:{'unreached;'*n} try: raise RuntimeError except RuntimeError: pass''')number=10**6//nt=min(repeat(f,number=number))/numberprint(f'{n:6}{t*1e6 :7.1f} μs')
The slowness happens when the unreached statements are anywhere before theraise, and not when they're anywhere after theraise (demo). So it seems what matters is location of theraise in the function. Long code before it somehow makes it slow.
This has a noticeable impact on real code I wrote (assuming I pinpointed the issue correctly): two solutions for a task, and one was oddly slower (~760 vs ~660 ns) despite executing the exact same sequence of bytecode operations. Just one jump length differed, leading to araise at a larger address.
Benchmark script with those two solutions and the relevant test case:
The functions shall return the one item from the iterable, or raise an exception if there are fewer or more than one. Testing with an empty iterable, both get the iterator, iterate it (nothing, since it's empty), then raise. The relevant difference appears to be that the slower one has theraise written at the bottom, whereas the faster one has it near the top.
Sample times:
664.4 ± 8.6 ns one_sequential 762.1 ± 28.8 ns one_nestedPython: 3.11.4 (main, Jun 24 2023, 10:18:04) [GCC 13.1.1 20230429]Code:
fromtimeitimporttimeitfromstatisticsimportmean,stdevfromitertoolsimportrepeat,starmap,isliceimportsysdefone_nested(iterable,too_short=None,too_long=None):it=iter(iterable)forfirstinit:forsecondinit:raisetoo_longorValueError('Expected exactly one item in iterable, but',f'got{first!r},{second!r}, and perhaps more.' )returnfirstraisetoo_shortorValueError('too few items in iterable (expected 1)')defone_sequential(iterable,too_short=None,too_long=None):it=iter(iterable)forfirstinit:breakelse:raisetoo_shortorValueError('too few items in iterable (expected 1)')forsecondinit:raisetoo_longorValueError('Expected exactly one item in iterable, but 'f'got{first!r},{second!r}, and perhaps more.' )returnfirstfuncs=one_nested,one_sequentialdefempty(f):iterable=iter(())too_short=RuntimeError()for_inrepeat(None,10**4):try:f(iterable,too_short)exceptRuntimeError:passforcaseinempty,:times= {f: []forfinfuncs}defstats(f):ts= [t*1e9fortinsorted(times[f])[:5]]returnf'{mean(ts):6.1f} ±{stdev(ts):4.1f} ns 'for_inrange(100):forfinfuncs:t=timeit(lambda:case(f),number=1)/1e4times[f].append(t)forfinsorted(funcs,key=stats):print(stats(f),f.__name__)print()print('Python:',sys.version)
CPython versions tested on:
3.10, 3.11
Operating systems tested on:
Linux, macOS
Linked PRs
- gh-109181: Speed up Traceback object creation by lazily compute the line number #111548
- [3.11] gh-109181: Speed up Traceback object creation by lazily compute the line number (GH-111548) #111550
- [3.12] gh-109181: Speed up Traceback object creation by lazily compute the line number (GH-111548) #111551
- [3.12] gh-109181: Fix refleak in tb_get_lineno() #111948
- [3.11] [3.12] gh-109181: Fix refleak in tb_get_lineno() (GH-111948) #111951