gh-154969: Record stop-the-world pause durations in pystats

Include/cpython/pystats.h

@@ -120,6 +120,10 @@ typedef struct _ft_stats {
     uint64_t qsbr_polls;
     // number of times stop-the-world mechanism was used
     uint64_t world_stops;
+    // total time the world was stopped, in nanoseconds
+    uint64_t world_stop_total_ns;
+    // duration of the longest single world stop, in nanoseconds
+    uint64_t world_stop_max_ns;
 } FTStats;
 #endif
 

Include/internal/pycore_interp_structs.h

@@ -422,6 +422,10 @@ struct _stoptheworld_state {
     Py_ssize_t thread_countdown;  // Number of threads that must pause.
 
     PyThreadState *requester; // Thread that requested the pause (may be NULL).
+
+#ifdef Py_STATS
+    PyTime_t start_time; // When the current pause was requested (for pystats).
+#endif
 };
 
 /* Tracks some rare events per-interpreter, used by the optimizer to turn on/off

Include/internal/pycore_stats.h

@@ -60,10 +60,22 @@ extern "C" {
 #define FT_STAT_MUTEX_SLEEP_INC() _Py_STATS_EXPR(ft_stats.mutex_sleeps++)
 #define FT_STAT_QSBR_POLL_INC() _Py_STATS_EXPR(ft_stats.qsbr_polls++)
 #define FT_STAT_WORLD_STOP_INC() _Py_STATS_EXPR(ft_stats.world_stops++)
+#define FT_STAT_WORLD_STOP_TIME(ns) \
+    do { \
+        PyStats *s = _PyStats_GET(); \
+        if (s != NULL) { \
+            uint64_t stw_ns = (uint64_t)(ns); \
+            s->ft_stats.world_stop_total_ns += stw_ns; \
+            if (stw_ns > s->ft_stats.world_stop_max_ns) { \
+                s->ft_stats.world_stop_max_ns = stw_ns; \
+            } \
+        } \
+    } while (0)
 #else
 #define FT_STAT_MUTEX_SLEEP_INC()
 #define FT_STAT_QSBR_POLL_INC()
 #define FT_STAT_WORLD_STOP_INC()
+#define FT_STAT_WORLD_STOP_TIME(ns)
 #endif
 
 // Export for '_opcode' shared extension
@@ -91,6 +103,7 @@ PyAPI_FUNC(PyObject*) _Py_GetSpecializationStats(void);
 #define FT_STAT_MUTEX_SLEEP_INC()
 #define FT_STAT_QSBR_POLL_INC()
 #define FT_STAT_WORLD_STOP_INC()
+#define FT_STAT_WORLD_STOP_TIME(ns)
 #endif  // !Py_STATS
 
 

Lib/test/test_pystats.py

@@ -1,6 +1,7 @@
 import sys
 import textwrap
 import unittest
+from test import support
 from test.support import script_helper
 
 # This function is available for the --enable-pystats config.
@@ -70,20 +71,39 @@ def run_test_code(
     test_code,
     args=[],
     env_vars=None,
+    stat_names=None,
 ):
-    """Run test code and return the value of the "set_class" stats counter.
+    """Run test code and return stats counters printed when it exits.
+
+    Returns the value of the "set_class" counter, or, when `stat_names` is
+    given, a dict of those counters collected from the same run.
     """
     code = textwrap.dedent(TEST_TEMPLATE)
     code = code.replace('_TEST_CODE_', textwrap.dedent(test_code))
     script_args = args + ['-c', code]
     env_vars = env_vars or {}
     res, _ = script_helper.run_python_until_end(*script_args, **env_vars)
     stderr = res.err.decode("ascii", "backslashreplace")
+
+    if stat_names is None:
+        stat_names = ('Rare event (set_class)',)
+        wanted_one = True
+    else:
+        wanted_one = False
+
+    # A run may print more than one block of stats, e.g. when it calls
+    # sys._stats_dump() itself and then prints again on the way out. Keep the
+    # first value seen for each counter.
+    found = {}
     for line in stderr.split('\n'):
-        if 'Rare event (set_class)' in line:
-            label, _, value = line.partition(':')
-            return value.strip()
-    return ''
+        label, sep, value = line.partition(':')
+        label = label.strip()
+        if sep and label in stat_names and label not in found:
+            found[label] = value.strip()
+
+    if wanted_one:
+        return found.get('Rare event (set_class)', '')
+    return found
 
 
 @unittest.skipUnless(HAVE_PYSTATS, "requires pystats build option")
@@ -211,5 +231,67 @@ def func_test(thread_id):
         self.assertEqual(stat_count, '0')
 
 
+@unittest.skipUnless(HAVE_PYSTATS, "requires pystats build option")
+@unittest.skipUnless(support.Py_GIL_DISABLED, "requires free-threaded build")
+class TestFreeThreadingStats(unittest.TestCase):
+    """Tests for the counters that only the free-threaded build keeps.
+    """
+
+    # How many times each worker thread stops the world.
+    COLLECTS = 10
+    WORKERS = 4
+
+    WORLD_STOPS = 'World stops (world_stops)'
+    TOTAL_NS = 'World stop total ns (world_stop_total_ns)'
+    MAX_NS = 'World stop max ns (world_stop_max_ns)'
+
+    def collect_in_threads(self):
+        """Stop the world from several threads, then report the counters.
+        """
+        code = f"""
+        import gc
+
+        THREADS = {self.WORKERS}
+
+        def func_start():
+            # Discard whatever start-up accumulated, so the counts below come
+            # from the collections the workers do and nothing else.
+            sys._stats_clear()
+
+        def func_test(thread_id):
+            for _ in range({self.COLLECTS}):
+                gc.collect()
+        """
+        return run_test_code(
+            code,
+            args=['-X', 'pystats'],
+            stat_names=(self.WORLD_STOPS, self.TOTAL_NS, self.MAX_NS),
+        )
+
+    def test_counters_are_summed_over_threads(self):
+        """Each thread's counts must be added, not overwrite the previous one.
+        """
+        stats = self.collect_in_threads()
+        stops = int(stats[self.WORLD_STOPS])
+        # Every worker stops the world COLLECTS times. Merging a thread's stats
+        # into the interpreter's by assignment would leave just one worker's
+        # share, so anything close to a single worker's count means the counts
+        # of the others were thrown away.
+        self.assertGreater(stops, 2 * self.COLLECTS)
+
+    def test_world_stop_durations_are_recorded(self):
+        stats = self.collect_in_threads()
+        stops = int(stats[self.WORLD_STOPS])
+        total = int(stats[self.TOTAL_NS])
+        longest = int(stats[self.MAX_NS])
+
+        self.assertGreater(stops, 0)
+        # Pauses that were counted must also have been timed.
+        self.assertGreater(total, 0)
+        self.assertGreater(longest, 0)
+        # A single pause cannot last longer than all of them put together.
+        self.assertLessEqual(longest, total)
+
+
 if __name__ == "__main__":
     unittest.main()

Misc/NEWS.d/next/Core_and_Builtins/2026-07-31-10-27-20.gh-issue-154969.rl2m1PNJIw.rst

@@ -0,0 +1 @@
+Statistics builds (``--enable-pystats``) of free-threaded CPython now record the total and maximum duration of stop-the-world pauses, and no longer overwrite the per-thread free-threading counters (mutex sleeps, QSBR polls, world stops) when merging thread statistics.

Python/pystate.c

@@ -2455,6 +2455,10 @@ stop_the_world(struct _stoptheworld_state *stw)
     stw->stop_event = (PyEvent){0};  // zero-initialize (unset)
     stw->requester = _PyThreadState_GET();  // may be NULL
     FT_STAT_WORLD_STOP_INC();
+#ifdef Py_STATS
+    // silently ignore error: cannot report error to the caller
+    (void)PyTime_MonotonicRaw(&stw->start_time);
+#endif
 
     _Py_FOR_EACH_STW_INTERP(stw, i) {
         _Py_FOR_EACH_TSTATE_UNLOCKED(i, t) {
@@ -2499,6 +2503,14 @@ start_the_world(struct _stoptheworld_state *stw)
     assert(PyMutex_IsLocked(&stw->mutex));
 
     HEAD_LOCK(runtime);
+#ifdef Py_STATS
+    // Records the full pause, from the stop request until the threads are
+    // about to be resumed.
+    PyTime_t now;
+    if (PyTime_MonotonicRaw(&now) == 0) {
+        FT_STAT_WORLD_STOP_TIME(now - stw->start_time);
+    }
+#endif
     stw->requested = 0;
     stw->world_stopped = 0;
     // Switch threads back to the detached state.

Python/pystats.c

@@ -343,6 +343,10 @@ print_ft_stats(FILE *out, FTStats *stats)
     fprintf(out, "Mutex sleeps (mutex_sleeps): %" PRIu64 "\n", stats->mutex_sleeps);
     fprintf(out, "QSBR polls (qsbr_polls): %" PRIu64 "\n", stats->qsbr_polls);
     fprintf(out, "World stops (world_stops): %" PRIu64 "\n", stats->world_stops);
+    fprintf(out, "World stop total ns (world_stop_total_ns): %" PRIu64 "\n",
+            stats->world_stop_total_ns);
+    fprintf(out, "World stop max ns (world_stop_max_ns): %" PRIu64 "\n",
+            stats->world_stop_max_ns);
 }
 #endif
 
@@ -506,9 +510,13 @@ merge_optimization_stats(OptimizationStats *dest, const OptimizationStats *src)
 static void
 merge_ft_stats(FTStats *dest, const FTStats *src)
 {
-    dest->mutex_sleeps = src->mutex_sleeps;
-    dest->qsbr_polls = src->qsbr_polls;
-    dest->world_stops = src->world_stops;
+    dest->mutex_sleeps += src->mutex_sleeps;
+    dest->qsbr_polls += src->qsbr_polls;
+    dest->world_stops += src->world_stops;
+    dest->world_stop_total_ns += src->world_stop_total_ns;
+    if (src->world_stop_max_ns > dest->world_stop_max_ns) {
+        dest->world_stop_max_ns = src->world_stop_max_ns;
+    }
 }
 
 static void