gh-116996: Add pystats about _Py_uop_analyse_and_optimize (GH-116997)

Author: mdboom

Include/cpython/pystats.h

@@ -19,6 +19,8 @@
 // Define _PY_INTERPRETER macro to increment interpreter_increfs and
 // interpreter_decrefs. Otherwise, increment increfs and decrefs.
 
+#include "pycore_uop_ids.h"
+
 #ifndef Py_CPYTHON_PYSTATS_H
 #  error "this header file must not be included directly"
 #endif
@@ -116,14 +118,17 @@ typedef struct _optimization_stats {
     uint64_t recursive_call;
     uint64_t low_confidence;
     uint64_t executors_invalidated;
-    UOpStats opcode[512];
+    UOpStats opcode[MAX_UOP_ID];
     uint64_t unsupported_opcode[256];
     uint64_t trace_length_hist[_Py_UOP_HIST_SIZE];
     uint64_t trace_run_length_hist[_Py_UOP_HIST_SIZE];
     uint64_t optimized_trace_length_hist[_Py_UOP_HIST_SIZE];
     uint64_t optimizer_attempts;
     uint64_t optimizer_successes;
     uint64_t optimizer_failure_reason_no_memory;
+    uint64_t remove_globals_builtins_changed;
+    uint64_t remove_globals_incorrect_keys;
+    uint64_t error_in_opcode[MAX_UOP_ID];
 } OptimizationStats;
 
 typedef struct _rare_event_stats {

Include/internal/pycore_code.h

@@ -308,6 +308,7 @@ extern int _PyStaticCode_Init(PyCodeObject *co);
 #define OPT_STAT_INC(name) do { if (_Py_stats) _Py_stats->optimization_stats.name++; } while (0)
 #define UOP_STAT_INC(opname, name) do { if (_Py_stats) { assert(opname < 512); _Py_stats->optimization_stats.opcode[opname].name++; } } while (0)
 #define OPT_UNSUPPORTED_OPCODE(opname) do { if (_Py_stats) _Py_stats->optimization_stats.unsupported_opcode[opname]++; } while (0)
+#define OPT_ERROR_IN_OPCODE(opname) do { if (_Py_stats) _Py_stats->optimization_stats.error_in_opcode[opname]++; } while (0)
 #define OPT_HIST(length, name) \
     do { \
         if (_Py_stats) { \
@@ -334,6 +335,7 @@ PyAPI_FUNC(PyObject*) _Py_GetSpecializationStats(void);
 #define OPT_STAT_INC(name) ((void)0)
 #define UOP_STAT_INC(opname, name) ((void)0)
 #define OPT_UNSUPPORTED_OPCODE(opname) ((void)0)
+#define OPT_ERROR_IN_OPCODE(opname) ((void)0)
 #define OPT_HIST(length, name) ((void)0)
 #define RARE_EVENT_STAT_INC(name) ((void)0)
 #endif  // !Py_STATS

Python/optimizer_analysis.c

@@ -139,6 +139,7 @@ remove_globals(_PyInterpreterFrame *frame, _PyUOpInstruction *buffer,
     PyInterpreterState *interp = _PyInterpreterState_GET();
     PyObject *builtins = frame->f_builtins;
     if (builtins != interp->builtins) {
+        OPT_STAT_INC(remove_globals_builtins_changed);
         return 1;
     }
     PyObject *globals = frame->f_globals;
@@ -170,6 +171,7 @@ remove_globals(_PyInterpreterFrame *frame, _PyUOpInstruction *buffer,
         switch(opcode) {
             case _GUARD_BUILTINS_VERSION:
                 if (incorrect_keys(inst, builtins)) {
+                    OPT_STAT_INC(remove_globals_incorrect_keys);
                     return 0;
                 }
                 if (interp->rare_events.builtin_dict >= _Py_MAX_ALLOWED_BUILTINS_MODIFICATIONS) {
@@ -190,6 +192,7 @@ remove_globals(_PyInterpreterFrame *frame, _PyUOpInstruction *buffer,
                 break;
             case _GUARD_GLOBALS_VERSION:
                 if (incorrect_keys(inst, globals)) {
+                    OPT_STAT_INC(remove_globals_incorrect_keys);
                     return 0;
                 }
                 uint64_t watched_mutations = get_mutations(globals);
@@ -238,6 +241,7 @@ remove_globals(_PyInterpreterFrame *frame, _PyUOpInstruction *buffer,
                 globals = func->func_globals;
                 builtins = func->func_builtins;
                 if (builtins != interp->builtins) {
+                    OPT_STAT_INC(remove_globals_builtins_changed);
                     return 1;
                 }
                 break;
@@ -358,6 +362,7 @@ optimize_uops(
 
     _Py_UOpsContext context;
     _Py_UOpsContext *ctx = &context;
+    uint32_t opcode = UINT16_MAX;
 
     if (_Py_uop_abstractcontext_init(ctx) < 0) {
         goto out_of_space;
@@ -374,8 +379,7 @@ optimize_uops(
          this_instr++) {
 
         int oparg = this_instr->oparg;
-        uint32_t opcode = this_instr->opcode;
-
+        opcode = this_instr->opcode;
         _Py_UopsSymbol **stack_pointer = ctx->frame->stack_pointer;
 
 #ifdef Py_DEBUG
@@ -410,6 +414,9 @@ optimize_uops(
 error:
     DPRINTF(3, "\n");
     DPRINTF(1, "Encountered error in abstract interpreter\n");
+    if (opcode <= MAX_UOP_ID) {
+        OPT_ERROR_IN_OPCODE(opcode);
+    }
     _Py_uop_abstractcontext_fini(ctx);
     return -1;
 

Python/specialize.c

@@ -247,6 +247,8 @@ print_optimization_stats(FILE *out, OptimizationStats *stats)
     fprintf(out, "Optimization optimizer successes: %" PRIu64 "\n", stats->optimizer_successes);
     fprintf(out, "Optimization optimizer failure no memory: %" PRIu64 "\n",
             stats->optimizer_failure_reason_no_memory);
+    fprintf(out, "Optimizer remove globals builtins changed: %" PRIu64 "\n", stats->remove_globals_builtins_changed);
+    fprintf(out, "Optimizer remove globals incorrect keys: %" PRIu64 "\n", stats->remove_globals_incorrect_keys);
 
     const char* const* names;
     for (int i = 0; i <= MAX_UOP_ID; i++) {
@@ -268,6 +270,17 @@ print_optimization_stats(FILE *out, OptimizationStats *stats)
             );
         }
     }
+
+    for (int i = 0; i < MAX_UOP_ID; i++) {
+        if (stats->error_in_opcode[i]) {
+            fprintf(
+                out,
+                "error_in_opcode[%s].count : %" PRIu64 "\n",
+                _PyUOpName(i),
+                stats->error_in_opcode[i]
+            );
+        }
+    }
 }
 
 static void

Tools/scripts/summarize_stats.py

@@ -513,6 +513,8 @@ def get_optimizer_stats(self) -> dict[str, tuple[int, int | None]]:
         attempts = self._data["Optimization optimizer attempts"]
         successes = self._data["Optimization optimizer successes"]
         no_memory = self._data["Optimization optimizer failure no memory"]
+        builtins_changed = self._data["Optimizer remove globals builtins changed"]
+        incorrect_keys = self._data["Optimizer remove globals incorrect keys"]
 
         return {
             Doc(
@@ -527,6 +529,14 @@ def get_optimizer_stats(self) -> dict[str, tuple[int, int | None]]:
                 "Optimizer no memory",
                 "The number of optimizations that failed due to no memory.",
             ): (no_memory, attempts),
+            Doc(
+                "Remove globals builtins changed",
+                "The builtins changed during optimization",
+            ): (builtins_changed, attempts),
+            Doc(
+                "Remove globals incorrect keys",
+                "The keys in the globals dictionary aren't what was expected",
+            ): (incorrect_keys, attempts),
         }
 
     def get_histogram(self, prefix: str) -> list[tuple[int, int]]:
@@ -1177,6 +1187,17 @@ def calc_unsupported_opcodes_table(stats: Stats) -> Rows:
             reverse=True,
         )
 
+    def calc_error_in_opcodes_table(stats: Stats) -> Rows:
+        error_in_opcodes = stats.get_opcode_stats("error_in_opcode")
+        return sorted(
+            [
+                (opcode, Count(count))
+                for opcode, count in error_in_opcodes.get_opcode_counts().items()
+            ],
+            key=itemgetter(1),
+            reverse=True,
+        )
+
     def iter_optimization_tables(base_stats: Stats, head_stats: Stats | None = None):
         if not base_stats.get_optimization_stats() or (
             head_stats is not None and not head_stats.get_optimization_stats()
@@ -1223,6 +1244,11 @@ def iter_optimization_tables(base_stats: Stats, head_stats: Stats | None = None)
                 )
             ],
         )
+        yield Section(
+            "Optimizer errored out with opcode",
+            "Optimization stopped after encountering this opcode",
+            [Table(("Opcode", "Count:"), calc_error_in_opcodes_table, JoinMode.CHANGE)],
+        )
 
     return Section(
         "Optimization (Tier 2) stats",