gh-104584: Baby steps towards generating and executing traces #105924

gvanrossum · 2023-06-19T18:13:25Z

This is mostly so we can benchmark how bad the overhead is.

Issue: Pluggable optimizer API #104584

gvanrossum · 2023-06-19T20:02:27Z

I ~~don't~~ now understand the compilation failure:

Error: ../cpython-ro-srcdir/Python/optimizer.c:304:21: error: variably modified ‘trace’ at file scope
  304 |     uop_instruction trace[MAX_TRACE_LENGTH];  // TODO: variable length
      |                     ^~~~~

Use '#define X 1' instead.

gvanrossum · 2023-06-20T02:22:30Z

Benchmark results say "1.00x slower": https://github.com/faster-cpython/benchmarking/blob/main/results/bm-20230619-3.13.0a0-6b23e0f/bm-20230619-linux-x86_64-gvanrossum-optim_exec-3.13.0a0-6b23e0f-vs-base.png (sorry, access only for Faster CPython team members).

mdboom · 2023-06-20T13:06:41Z

The public link is here: https://github.com/faster-cpython/benchmarking-public/blob/main/results/bm-20230619-3.13.0a0-6b23e0f/bm-20230619-linux-x86_64-gvanrossum-optim_exec-3.13.0a0-6b23e0f-vs-base.png

(Macros inherit flags from components, but shouldn't inherit IS_UOP.)

markshannon · 2023-06-26T08:49:54Z

The oparg in normal bytecode is an unsigned 32 bit integer, we should use uint32_t but we use int. In practice it is fine as
0 <= oparg < (2**31) is always true.
The 64 bit caches hold a pointer, so an explicit cast from uint64_t to uintptr_t should keep MSVC happy.

Now test_mmap on Windows passes, and hopefully so does test_threading on UNIX.

Instead of `int oparg` we now have `uint64_t operand`. In the Tier 2 interpreter, we add `int oparg` and set it to a truncated version of `operand` so instructions can reference it.

gvanrossum · 2023-06-26T17:48:45Z

The latest change indeed fixes test_mmap. It does nothing for test_threading, that was a typo.

I had hoped it would also fix test_memoryview, and while it reduces the failure rate there from 12 to 1 failing test, there is still that one failing test...

======================================================================
ERROR: test_contextmanager (test.test_memoryview.ArrayMemorySliceSliceTest.test_contextmanager)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/guido/cpython/Lib/test/test_memoryview.py", line 288, in test_contextmanager
    self._check_released(m, tp)
  File "/Users/guido/cpython/Lib/test/test_memoryview.py", line 273, in _check_released
    with m:
         ^
ValueError: operation forbidden on released memoryview object

----------------------------------------------------------------------

I will continue to debug this for a bit, but I'll probably choose to just disable the offending bytecode again.

UPDATE: I gave up. I have a hunch it's related to a trace that contains two BEFORE_WITH uops where the second one fails, and then possibly the exception table might be off? But that ought to be driven by the SET_IP logic, which I believe is correct. I don't want to dive into this, so I just chickened out by skipping those opcodes.

Apparently the fix using SET_LOCALS_FROM_FRAME() isn't enough (it fixes some but not all failures). Possibly the problem is due to having *two* BEFORE_WITH uops in one trace? Unclear what's wrong with that opcode.

bedevere-bot · 2023-06-26T18:50:27Z

🤖 New build scheduled with the buildbot fleet by @gvanrossum for commit 4bd7bb6 🤖

If you want to schedule another build, you need to add the 🔨 test-with-refleak-buildbots label again.

gvanrossum · 2023-06-26T18:53:45Z

Regarding new files, I don't think it will stand in the way of progress if this were merged with the superblock creation code in Python/optimizer.c and the trace interpreter in Python/ceval.c. If at some point in the future that becomes a problem we can refactor it then. I'd like this PR to remain a spike, not become a marathon.

Last bits of work:

Run with refleaks bot
pylifecycle.c work
Add Misc/NEWS.d entry

The uops optimizer is enabled in the main interpreter when either: - -Xuops is passed; or - PYTHONUOPS=1 is set. The env var for uops debugging is now called PYTHONUOPSDEBUG. It only has an effect when configured --with-pydebug *and* the uops optimizer is enabled (see above). Also fixed a compiler warning about %ld with an int64 arg.

Those tests now only fail when run with -Xuops. We should probably fix the uop executor instead. Also, test_embed now passes even with -Xuops. This reverts commit 91dd86c.

Python/optimizer.c

bedevere-bot · 2023-06-26T21:48:39Z

🤖 New build scheduled with the buildbot fleet by @gvanrossum for commit 6606c5d 🤖

If you want to schedule another build, you need to add the 🔨 test-with-refleak-buildbots label again.

gvanrossum · 2023-06-26T23:35:09Z

@markshannon I have a niggling suspicion that if the very first uop in a trace ends with a failing DEOPT_IF (or ERROR_IF?), it will do the wrong thing, since next_instr and frame->prev_instr are still set where the ENTER_EXECUTOR found it. But I don't think any tests have triggered such a situation. If I'm right, the fix would be to start the trace with a SET_IP uops. Does that make sense to you?

gvanrossum · 2023-06-27T00:51:02Z

The refleaks run failed, but that was an existing issue (#105273). They didn't test there were no refleaks left, because I also pushed the change that requires -Xuops to enable the new optimizer. But the leak that @kumaraditya303 found was pretty glaring, and I ran some tests that were previously leaking locally, and those no longer leaked, so I am okay with this aspect. I will now add a news blurb and merge. We can reiterate after that.

bedevere-bot · 2023-06-27T03:01:50Z

⚠️⚠️⚠️ Buildbot failure ⚠️⚠️⚠️

Hi! The buildbot ARM Raspbian 3.x has failed when building commit 51fc725.

What do you need to do:

Don't panic.
Check the buildbot page in the devguide if you don't know what the buildbots are or how they work.
Go to the page of the buildbot that failed (https://buildbot.python.org/all/#builders/424/builds/4281) and take a look at the build logs.
Check if the failure is related to this commit (51fc725) or if it is a false positive.
If the failure is related to this commit, please, reflect that on the issue and make a new Pull Request with a fix.

You can take a look at the buildbot page here:

https://buildbot.python.org/all/#builders/424/builds/4281

Summary of the results of the build (if available):

== Tests result: ENV CHANGED ==

426 tests OK.

10 slowest tests:

test_venv: 10 min 2 sec
test_source_encoding: 9 min 11 sec
test_largefile: 8 min 43 sec
test_multiprocessing_spawn: 6 min 58 sec
test_math: 4 min 25 sec
test_peg_generator: 4 min 19 sec
test_cppext: 4 min 9 sec
test_codecs: 2 min 58 sec
test_concurrent_futures: 2 min 58 sec
test_argparse: 2 min 33 sec

1 test altered the execution environment:
test_multiprocessing_spawn

19 tests skipped:
test.test_asyncio.test_windows_events
test.test_asyncio.test_windows_utils test_devpoll test_idle
test_ioctl test_kqueue test_launcher test_perf_profiler
test_startfile test_tcl test_tkinter test_ttk test_ttk_textonly
test_turtle test_winconsoleio test_winreg test_winsound test_wmi
test_zipfile64

Total duration: 39 min 6 sec

Click to see traceback logs

remote: Enumerating objects: 36, done.        
remote: Counting objects:   2% (1/35)        
remote: Counting objects:   5% (2/35)        
remote: Counting objects:   8% (3/35)        
remote: Counting objects:  11% (4/35)        
remote: Counting objects:  14% (5/35)        
remote: Counting objects:  17% (6/35)        
remote: Counting objects:  20% (7/35)        
remote: Counting objects:  22% (8/35)        
remote: Counting objects:  25% (9/35)        
remote: Counting objects:  28% (10/35)        
remote: Counting objects:  31% (11/35)        
remote: Counting objects:  34% (12/35)        
remote: Counting objects:  37% (13/35)        
remote: Counting objects:  40% (14/35)        
remote: Counting objects:  42% (15/35)        
remote: Counting objects:  45% (16/35)        
remote: Counting objects:  48% (17/35)        
remote: Counting objects:  51% (18/35)        
remote: Counting objects:  54% (19/35)        
remote: Counting objects:  57% (20/35)        
remote: Counting objects:  60% (21/35)        
remote: Counting objects:  62% (22/35)        
remote: Counting objects:  65% (23/35)        
remote: Counting objects:  68% (24/35)        
remote: Counting objects:  71% (25/35)        
remote: Counting objects:  74% (26/35)        
remote: Counting objects:  77% (27/35)        
remote: Counting objects:  80% (28/35)        
remote: Counting objects:  82% (29/35)        
remote: Counting objects:  85% (30/35)        
remote: Counting objects:  88% (31/35)        
remote: Counting objects:  91% (32/35)        
remote: Counting objects:  94% (33/35)        
remote: Counting objects:  97% (34/35)        
remote: Counting objects: 100% (35/35)        
remote: Counting objects: 100% (35/35), done.        
remote: Compressing objects:   3% (1/26)        
remote: Compressing objects:   7% (2/26)        
remote: Compressing objects:  11% (3/26)        
remote: Compressing objects:  15% (4/26)        
remote: Compressing objects:  19% (5/26)        
remote: Compressing objects:  23% (6/26)        
remote: Compressing objects:  26% (7/26)        
remote: Compressing objects:  30% (8/26)        
remote: Compressing objects:  34% (9/26)        
remote: Compressing objects:  38% (10/26)        
remote: Compressing objects:  42% (11/26)        
remote: Compressing objects:  46% (12/26)        
remote: Compressing objects:  50% (13/26)        
remote: Compressing objects:  53% (14/26)        
remote: Compressing objects:  57% (15/26)        
remote: Compressing objects:  61% (16/26)        
remote: Compressing objects:  65% (17/26)        
remote: Compressing objects:  69% (18/26)        
remote: Compressing objects:  73% (19/26)        
remote: Compressing objects:  76% (20/26)        
remote: Compressing objects:  80% (21/26)        
remote: Compressing objects:  84% (22/26)        
remote: Compressing objects:  88% (23/26)        
remote: Compressing objects:  92% (24/26)        
remote: Compressing objects:  96% (25/26)        
remote: Compressing objects: 100% (26/26)        
remote: Compressing objects: 100% (26/26), done.        
remote: Total 36 (delta 10), reused 10 (delta 9), pack-reused 1        
From https://github.com/python/cpython
 * branch                  main       -> FETCH_HEAD
Note: switching to '51fc72511733353de15bc633a3d7b6da366842e4'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by switching back to a branch.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -c with the switch command. Example:

  git switch -c <new-branch-name>

Or undo this operation with:

  git switch -

Turn off this advice by setting config variable advice.detachedHead to false

HEAD is now at 51fc725117 gh-104584: Baby steps towards generating and executing traces (#105924)
Switched to and reset branch 'main'

In file included from ./Include/Python.h:35,
                 from Python/ceval.c:5:
Python/ceval.c: In function ‘_PyUopExecute’:
Python/ceval_macros.h:271:31: warning: array subscript 310 is above array bounds of ‘const uint8_t[256]’ {aka ‘const unsigned char[256]’} [-Warray-bounds]
  271 |         assert(_PyOpcode_Deopt[opcode] == (INSTNAME));      \
      |                ~~~~~~~~~~~~~~~^~~~~~~~
Python/executor_cases.c.h:210:13: note: in expansion of macro ‘DEOPT_IF’
  210 |             DEOPT_IF(!PyUnicode_CheckExact(right), BINARY_OP);
      |             ^~~~~~~~
In file included from Python/ceval.c:16:
./Include/internal/pycore_opcode.h:17:22: note: while referencing ‘_PyOpcode_Deopt’
   17 | extern const uint8_t _PyOpcode_Deopt[256];
      |                      ^~~~~~~~~~~~~~~
In file included from ./Include/Python.h:35,
                 from Python/ceval.c:5:
Python/ceval_macros.h:271:31: warning: array subscript 310 is above array bounds of ‘const uint8_t[256]’ {aka ‘const unsigned char[256]’} [-Warray-bounds]
  271 |         assert(_PyOpcode_Deopt[opcode] == (INSTNAME));      \
      |                ~~~~~~~~~~~~~~~^~~~~~~~
Python/executor_cases.c.h:209:13: note: in expansion of macro ‘DEOPT_IF’
  209 |             DEOPT_IF(!PyUnicode_CheckExact(left), BINARY_OP);
      |             ^~~~~~~~
In file included from Python/ceval.c:16:
./Include/internal/pycore_opcode.h:17:22: note: while referencing ‘_PyOpcode_Deopt’
   17 | extern const uint8_t _PyOpcode_Deopt[256];
      |                      ^~~~~~~~~~~~~~~
In file included from ./Include/Python.h:35,
                 from Python/ceval.c:5:
Python/ceval_macros.h:271:31: warning: array subscript 306 is above array bounds of ‘const uint8_t[256]’ {aka ‘const unsigned char[256]’} [-Warray-bounds]
  271 |         assert(_PyOpcode_Deopt[opcode] == (INSTNAME));      \
      |                ~~~~~~~~~~~~~~~^~~~~~~~
Python/executor_cases.c.h:160:13: note: in expansion of macro ‘DEOPT_IF’
  160 |             DEOPT_IF(!PyFloat_CheckExact(right), BINARY_OP);
      |             ^~~~~~~~
In file included from Python/ceval.c:16:
./Include/internal/pycore_opcode.h:17:22: note: while referencing ‘_PyOpcode_Deopt’
   17 | extern const uint8_t _PyOpcode_Deopt[256];
      |                      ^~~~~~~~~~~~~~~
In file included from ./Include/Python.h:35,
                 from Python/ceval.c:5:
Python/ceval_macros.h:271:31: warning: array subscript 306 is above array bounds of ‘const uint8_t[256]’ {aka ‘const unsigned char[256]’} [-Warray-bounds]
  271 |         assert(_PyOpcode_Deopt[opcode] == (INSTNAME));      \
      |                ~~~~~~~~~~~~~~~^~~~~~~~
Python/executor_cases.c.h:159:13: note: in expansion of macro ‘DEOPT_IF’
  159 |             DEOPT_IF(!PyFloat_CheckExact(left), BINARY_OP);
      |             ^~~~~~~~
In file included from Python/ceval.c:16:
./Include/internal/pycore_opcode.h:17:22: note: while referencing ‘_PyOpcode_Deopt’
   17 | extern const uint8_t _PyOpcode_Deopt[256];
      |                      ^~~~~~~~~~~~~~~
In file included from ./Include/Python.h:35,
                 from Python/ceval.c:5:
Python/ceval_macros.h:271:31: warning: array subscript 302 is above array bounds of ‘const uint8_t[256]’ {aka ‘const unsigned char[256]’} [-Warray-bounds]
  271 |         assert(_PyOpcode_Deopt[opcode] == (INSTNAME));      \
      |                ~~~~~~~~~~~~~~~^~~~~~~~
Python/executor_cases.c.h:110:13: note: in expansion of macro ‘DEOPT_IF’
  110 |             DEOPT_IF(!PyLong_CheckExact(right), BINARY_OP);
      |             ^~~~~~~~
In file included from Python/ceval.c:16:
./Include/internal/pycore_opcode.h:17:22: note: while referencing ‘_PyOpcode_Deopt’
   17 | extern const uint8_t _PyOpcode_Deopt[256];
      |                      ^~~~~~~~~~~~~~~
In file included from ./Include/Python.h:35,
                 from Python/ceval.c:5:
Python/ceval_macros.h:271:31: warning: array subscript 302 is above array bounds of ‘const uint8_t[256]’ {aka ‘const unsigned char[256]’} [-Warray-bounds]
  271 |         assert(_PyOpcode_Deopt[opcode] == (INSTNAME));      \
      |                ~~~~~~~~~~~~~~~^~~~~~~~
Python/executor_cases.c.h:109:13: note: in expansion of macro ‘DEOPT_IF’
  109 |             DEOPT_IF(!PyLong_CheckExact(left), BINARY_OP);
      |             ^~~~~~~~
In file included from Python/ceval.c:16:
./Include/internal/pycore_opcode.h:17:22: note: while referencing ‘_PyOpcode_Deopt’
   17 | extern const uint8_t _PyOpcode_Deopt[256];
      |                      ^~~~~~~~~~~~~~~
./Modules/_testcapi/heaptype_relative.c: In function ‘make_sized_heaptypes’:
./Modules/_testcapi/heaptype_relative.c:62:28: warning: cast from pointer to integer of different size [-Wpointer-to-int-cast]
   62 |                            (unsigned long long)data_ptr,
      |                            ^

make: *** [Makefile:2002: buildbottest] Error 3

gvanrossum added 17 commits June 19, 2023 18:00

Boilerplate for new uop optimizer+executor

3008fc7

Make uop optimizer execute a LOAD_FAST

512b764

Generalize uop optimizer infrastructure

52742c8

Give uop_execute an instruction decoding loop

4de0468

Make the translator use a switch

5ded690

Support LOAD_FAST_LOAD_FAST

e41acc0

Support LOAD_CONST

76ccf2d

Fix edge case for LOAD_FAST_LOAD_FAST

3001dde

Generate SET_IP after each instr

a7d2cba

Turn stats into properties (tp_members)

e00703c

Comment out fprintfs

3d41ffe

Enable UOp optimizer by default in main interpreter

7db1d12

The world isn't ready for 'const int X = 1;'

17bcc61

Use '#define X 1' instead.

Avoid MSC warning about implicit cast

e07bc4c

Add missing cast in pylifecycle.c

02b0624

Use write_provenance_header() more

b5feec7

Generate (some) cases for the executor

775df6e

gvanrossum force-pushed the optim-exec branch from 6b23e0f to f05a287 Compare June 20, 2023 03:12

gvanrossum added 2 commits June 19, 2023 21:32

Recompile flowgraph.c when opcodse_metadata.h changes

e2855ca

Add uop status to opcode metadata

0ad18cf

gvanrossum force-pushed the optim-exec branch from f05a287 to 0ad18cf Compare June 20, 2023 04:33

gvanrossum added 6 commits June 20, 2023 10:22

Use macros from ceval_macros.h

f5c8316

Interim -- opcode without oparg using cache entry

13c6bd2

ERROR_IF is no longer a dirty word (but errors crash)

1b1584c

Regenerate generated_cases.c.h

c2c1868

Hacky way to avoid flagging macros as uops

340570f

(Macros inherit flags from components, but shouldn't inherit IS_UOP.)

Support DEOPT_IF

96fa5ef

gvanrossum added 2 commits June 26, 2023 09:55

Fix bug in ENTER_EXECUTOR - on error go to resume_with_error

2254f83

Now test_mmap on Windows passes, and hopefully so does test_threading on UNIX.

Silence warnings on Windows

2f6603e

Instead of `int oparg` we now have `uint64_t operand`. In the Tier 2 interpreter, we add `int oparg` and set it to a truncated version of `operand` so instructions can reference it.

gvanrossum added 2 commits June 26, 2023 10:55

Replace oparg with operand in more debug output

00f8f2c

Fix test_memoryview again by excluding BEFORE_WITH

4bd7bb6

Apparently the fix using SET_LOCALS_FROM_FRAME() isn't enough (it fixes some but not all failures). Possibly the problem is due to having *two* BEFORE_WITH uops in one trace? Unclear what's wrong with that opcode.

gvanrossum added the 🔨 test-with-refleak-buildbots Test PR w/ refleak buildbots; report in status section label Jun 26, 2023

bedevere-bot removed the 🔨 test-with-refleak-buildbots Test PR w/ refleak buildbots; report in status section label Jun 26, 2023

gvanrossum added 3 commits June 26, 2023 12:19

Revert "Fix 4/6 failing tests"

9c04e40

Those tests now only fail when run with -Xuops. We should probably fix the uop executor instead. Also, test_embed now passes even with -Xuops. This reverts commit 91dd86c.

Use PRIu64 instead of %lld/%llu formats

39bc8fe

kumaraditya303 reviewed Jun 26, 2023

View reviewed changes

Python/optimizer.c Outdated Show resolved Hide resolved

Remove superfluous INCREF -- hope it fixes the refleaks

6606c5d

gvanrossum added the 🔨 test-with-refleak-buildbots Test PR w/ refleak buildbots; report in status section label Jun 26, 2023

bedevere-bot removed the 🔨 test-with-refleak-buildbots Test PR w/ refleak buildbots; report in status section label Jun 26, 2023

gvanrossum mentioned this pull request Jun 27, 2023

test_capi fails if run with --forever argument #105273

Closed

📜🤖 Added by blurb_it.

c14e104

gvanrossum merged commit 51fc725 into python:main Jun 27, 2023

bedevere-bot removed the awaiting core review label Jun 27, 2023

gvanrossum mentioned this pull request Jun 27, 2023

gh-104584: Add #line directives to executor_cases.c.h #106126

Merged

This was referenced Jun 27, 2023

gh-104584: Fix assert in DEOPT macro -- should fix buildbot #106131

Merged

gh-106290: Fix edge cases around uops #106319

Merged

gvanrossum deleted the optim-exec branch July 7, 2023 21:19

gvanrossum mentioned this pull request Nov 3, 2023

GH-111485: Remove some special cases from the code generator and bytecodes.c #111540

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

gh-104584: Baby steps towards generating and executing traces #105924

gh-104584: Baby steps towards generating and executing traces #105924

gvanrossum commented Jun 19, 2023 •

edited by bedevere-bot

Loading

gvanrossum commented Jun 19, 2023 •

edited

Loading

gvanrossum commented Jun 20, 2023

mdboom commented Jun 20, 2023

markshannon commented Jun 26, 2023

gvanrossum commented Jun 26, 2023 •

edited

Loading

bedevere-bot commented Jun 26, 2023

gvanrossum commented Jun 26, 2023 •

edited

Loading

bedevere-bot commented Jun 26, 2023

gvanrossum commented Jun 26, 2023

gvanrossum commented Jun 27, 2023

bedevere-bot commented Jun 27, 2023

gh-104584: Baby steps towards generating and executing traces #105924

gh-104584: Baby steps towards generating and executing traces #105924

Conversation

gvanrossum commented Jun 19, 2023 • edited by bedevere-bot Loading

gvanrossum commented Jun 19, 2023 • edited Loading

gvanrossum commented Jun 20, 2023

mdboom commented Jun 20, 2023

markshannon commented Jun 26, 2023

gvanrossum commented Jun 26, 2023 • edited Loading

bedevere-bot commented Jun 26, 2023

gvanrossum commented Jun 26, 2023 • edited Loading

bedevere-bot commented Jun 26, 2023

gvanrossum commented Jun 26, 2023

gvanrossum commented Jun 27, 2023

bedevere-bot commented Jun 27, 2023

⚠️⚠️⚠️ Buildbot failure ⚠️⚠️⚠️

gvanrossum commented Jun 19, 2023 •

edited by bedevere-bot

Loading

gvanrossum commented Jun 19, 2023 •

edited

Loading

gvanrossum commented Jun 26, 2023 •

edited

Loading

gvanrossum commented Jun 26, 2023 •

edited

Loading