gh-140358: Bring back elapsed time and unreachable count to gc debug output (#140359)

diff --git a/Lib/test/test_gc.py b/Lib/test/test_gc.py
index 70d9d009fa8bfdfb80b62717ff68d26ea206eba6..08055bb8e6bd41c81aa1d21aca4b62afc34cf6bc 100644 (file)
--- a/Lib/test/test_gc.py
+++ b/Lib/test/test_gc.py
@@ -801,6 +801,32 @@ class GCTests(unittest.TestCase):
             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:

diff --git a/Misc/NEWS.d/next/Core_and_Builtins/2025-10-20-11-24-36.gh-issue-140358.UQuKdV.rst b/Misc/NEWS.d/next/Core_and_Builtins/2025-10-20-11-24-36.gh-issue-140358.UQuKdV.rst
new file mode 100644 (file)
index 0000000..739228f
--- /dev/null
+++ b/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.

diff --git a/Python/gc.c b/Python/gc.c
index 79c7476f4a9a74588a57aef87f990470bec6b59f..fd724301c769bf8dda17e5d6a554fcffe3c7a37e 100644 (file)
--- a/Python/gc.c
+++ b/Python/gc.c
@@ -2077,8 +2077,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()) {
@@ -2115,6 +2117,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;
 }