[3.14] gh-140358: Bring back elapsed time and unreachable count to gc debug output (GH-140359) (#140405)

Co-authored-by: Pål Grønås Drange <[email protected]>

Author: miss-islington

Lib/test/test_gc.py

@@ -776,6 +776,32 @@ def __del__(self):
             rc, out, err = assert_python_ok('-c', code)
             self.assertEqual(out.strip(), b'__del__ called')
 
+    @unittest.skipIf(Py_GIL_DISABLED, "requires GC generations or increments")
+    def test_gc_debug_stats(self):
+        # Checks that debug information is printed to stderr
+        # when DEBUG_STATS is set.
+        code = """if 1:
+            import gc
+            gc.set_debug(%s)
+            gc.collect()
+            """
+        _, _, err = assert_python_ok("-c", code % "gc.DEBUG_STATS")
+        self.assertRegex(err, b"gc: collecting generation [0-9]+")
+        self.assertRegex(
+            err,
+            b"gc: objects in each generation: [0-9]+ [0-9]+ [0-9]+",
+        )
+        self.assertRegex(
+            err, b"gc: objects in permanent generation: [0-9]+"
+        )
+        self.assertRegex(
+            err,
+            b"gc: done, .* unreachable, .* uncollectable, .* elapsed",
+        )
+
+        _, _, err = assert_python_ok("-c", code % "0")
+        self.assertNotIn(b"elapsed", err)
+
     def test_global_del_SystemExit(self):
         code = """if 1:
             class ClassWithDel:

Misc/NEWS.d/next/Core_and_Builtins/2025-10-20-11-24-36.gh-issue-140358.UQuKdV.rst

@@ -0,0 +1,4 @@
+Restore elapsed time and unreachable object count in GC debug output. These
+were inadvertently removed during a refactor of ``gc.c``. The debug log now
+again reports elapsed collection time and the number of unreachable objects.
+Contributed by Pål Grønås Drange.

Python/gc.c

@@ -2024,8 +2024,10 @@ _PyGC_Collect(PyThreadState *tstate, int generation, _PyGC_Reason reason)
     if (reason != _Py_GC_REASON_SHUTDOWN) {
         invoke_gc_callback(gcstate, "start", generation, &stats);
     }
+    PyTime_t t1;
     if (gcstate->debug & _PyGC_DEBUG_STATS) {
         PySys_WriteStderr("gc: collecting generation %d...\n", generation);
+        (void)PyTime_PerfCounterRaw(&t1);
         show_stats_each_generations(gcstate);
     }
     if (PyDTrace_GC_START_ENABLED()) {
@@ -2062,6 +2064,17 @@ _PyGC_Collect(PyThreadState *tstate, int generation, _PyGC_Reason reason)
 #endif
     validate_spaces(gcstate);
     _Py_atomic_store_int(&gcstate->collecting, 0);
+
+    if (gcstate->debug & _PyGC_DEBUG_STATS) {
+        PyTime_t t2;
+        (void)PyTime_PerfCounterRaw(&t2);
+        double d = PyTime_AsSecondsDouble(t2 - t1);
+        PySys_WriteStderr(
+            "gc: done, %zd unreachable, %zd uncollectable, %.4fs elapsed\n",
+            stats.collected + stats.uncollectable, stats.uncollectable, d
+        );
+    }
+
     return stats.uncollectable + stats.collected;
 }