FazBrowse GitHub Viewer | Trending |
URL:
| Home
Tools: [Download Repo ZIP]   [Original HTTPS Page]

GH-140638: Add a GC "duration" stat (GH-141720) · python/cpython@598d4c6 · GitHub

/ cpython Public

Commit 598d4c6

Browse files
brandtbucher
authored
GH-140638: Add a GC "duration" stat (GH-141720)
1 parent b3b63e8 commit 598d4c6

7 files changed

Lines changed: 67 additions & 32 deletions

File tree

‎Doc/library/gc.rst‎

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -108,10 +108,16 @@ The :mod:`gc` module provides the following functions:
108108

109109
* ``uncollectable`` is the total number of objects which were found
110110
to be uncollectable (and were therefore moved to the :data:`garbage`
111-
list) inside this generation.
111+
list) inside this generation;
112+
113+
* ``duration`` is the total time in seconds spent in collections for this
114+
generation.
112115

113116
.. versionadded:: 3.4
114117

118+
.. versionchanged:: next
119+
Add ``duration``.
120+
115121

116122
.. function:: set_threshold(threshold0, [threshold1, [threshold2]])
117123

@@ -313,6 +319,9 @@ values but should not rebind them):
313319
"uncollectable": When *phase* is "stop", the number of objects
314320
that could not be collected and were put in :data:`garbage`.
315321

322+
"duration": When *phase* is "stop", the time in seconds spent in the
323+
collection.
324+
316325
Applications can add their own callbacks to this list. The primary
317326
use cases are:
318327

@@ -325,6 +334,9 @@ values but should not rebind them):
325334

326335
.. versionadded:: 3.3
327336

337+
.. versionchanged:: next
338+
Add "duration".
339+
328340

329341
The following constants are provided for use with :func:`set_debug`:
330342

‎Include/internal/pycore_interp_structs.h‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -179,6 +179,8 @@ struct gc_collection_stats {
179179
Py_ssize_t collected;
180180
/* total number of uncollectable objects (put into gc.garbage) */
181181
Py_ssize_t uncollectable;
182+
// Duration of the collection in seconds:
183+
double duration;
182184
};
183185

184186
/* Running stats per generation */
@@ -189,6 +191,8 @@ struct gc_generation_stats {
189191
Py_ssize_t collected;
190192
/* total number of uncollectable objects (put into gc.garbage) */
191193
Py_ssize_t uncollectable;
194+
// Duration of the collection in seconds:
195+
double duration;
192196
};
193197

194198
enum _GCPhase {

‎Lib/test/test_gc.py‎

Lines changed: 22 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -847,10 +847,11 @@ def test_get_stats(self):
847847
for st in stats:
848848
self.assertIsInstance(st, dict)
849849
self.assertEqual(set(st),
850-
{"collected", "collections", "uncollectable"})
850+
{"collected", "collections", "uncollectable", "duration"})
851851
self.assertGreaterEqual(st["collected"], 0)
852852
self.assertGreaterEqual(st["collections"], 0)
853853
self.assertGreaterEqual(st["uncollectable"], 0)
854+
self.assertGreaterEqual(st["duration"], 0)
854855
# Check that collection counts are incremented correctly
855856
if gc.isenabled():
856857
self.addCleanup(gc.enable)
@@ -861,11 +862,25 @@ def test_get_stats(self):
861862
self.assertEqual(new[0]["collections"], old[0]["collections"] + 1)
862863
self.assertEqual(new[1]["collections"], old[1]["collections"])
863864
self.assertEqual(new[2]["collections"], old[2]["collections"])
865+
self.assertGreater(new[0]["duration"], old[0]["duration"])
866+
self.assertEqual(new[1]["duration"], old[1]["duration"])
867+
self.assertEqual(new[2]["duration"], old[2]["duration"])
868+
for stat in ["collected", "uncollectable"]:
869+
self.assertGreaterEqual(new[0][stat], old[0][stat])
870+
self.assertEqual(new[1][stat], old[1][stat])
871+
self.assertEqual(new[2][stat], old[2][stat])
864872
gc.collect(2)
865-
new = gc.get_stats()
866-
self.assertEqual(new[0]["collections"], old[0]["collections"] + 1)
873+
old, new = new, gc.get_stats()
874+
self.assertEqual(new[0]["collections"], old[0]["collections"])
867875
self.assertEqual(new[1]["collections"], old[1]["collections"])
868876
self.assertEqual(new[2]["collections"], old[2]["collections"] + 1)
877+
self.assertEqual(new[0]["duration"], old[0]["duration"])
878+
self.assertEqual(new[1]["duration"], old[1]["duration"])
879+
self.assertGreater(new[2]["duration"], old[2]["duration"])
880+
for stat in ["collected", "uncollectable"]:
881+
self.assertEqual(new[0][stat], old[0][stat])
882+
self.assertEqual(new[1][stat], old[1][stat])
883+
self.assertGreaterEqual(new[2][stat], old[2][stat])
869884

870885
def test_freeze(self):
871886
gc.freeze()
@@ -1298,9 +1313,10 @@ def test_collect(self):
12981313
# Check that we got the right info dict for all callbacks
12991314
for v in self.visit:
13001315
info = v[2]
1301-
self.assertTrue("generation" in info)
1302-
self.assertTrue("collected" in info)
1303-
self.assertTrue("uncollectable" in info)
1316+
self.assertIn("generation", info)
1317+
self.assertIn("collected", info)
1318+
self.assertIn("uncollectable", info)
1319+
self.assertIn("duration", info)
13041320

13051321
def test_collect_generation(self):
13061322
self.preclean()

‎Misc/NEWS.d/next/Core_and_Builtins/2025-11-18-07-45-37.gh-issue-140638.i06qxD.rst‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,2 @@
1+
Expose a ``"duration"`` stat in :func:`gc.get_stats` and
2+
:data:`gc.callbacks`.

‎Modules/gcmodule.c‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -358,10 +358,11 @@ gc_get_stats_impl(PyObject *module)
358358
for (i = 0; i < NUM_GENERATIONS; i++) {
359359
PyObject *dict;
360360
st = &stats[i];
361-
dict = Py_BuildValue("{snsnsn}",
361+
dict = Py_BuildValue("{snsnsnsd}",
362362
"collections", st->collections,
363363
"collected", st->collected,
364-
"uncollectable", st->uncollectable
364+
"uncollectable", st->uncollectable,
365+
"duration", st->duration
365366
);
366367
if (dict == NULL)
367368
goto error;

‎Python/gc.c‎

Lines changed: 10 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -1363,6 +1363,7 @@ gc_list_set_space(PyGC_Head *list, int space)
13631363
static void
13641364
add_stats(GCState *gcstate, int gen, struct gc_collection_stats *stats)
13651365
{
1366+
gcstate->generation_stats[gen].duration += stats->duration;
13661367
gcstate->generation_stats[gen].collected += stats->collected;
13671368
gcstate->generation_stats[gen].uncollectable += stats->uncollectable;
13681369
gcstate->generation_stats[gen].collections += 1;
@@ -1387,7 +1388,6 @@ gc_collect_young(PyThreadState *tstate,
13871388
validate_spaces(gcstate);
13881389
gcstate->young.count = 0;
13891390
gcstate->old[gcstate->visited_space].count++;
1390-
add_stats(gcstate, 0, stats);
13911391
validate_spaces(gcstate);
13921392
}
13931393

@@ -1701,7 +1701,6 @@ gc_collect_increment(PyThreadState *tstate, struct gc_collection_stats *stats)
17011701
assert(gc_list_is_empty(&increment));
17021702
gcstate->work_to_do -= increment_size;
17031703

1704-
add_stats(gcstate, 1, stats);
17051704
if (gc_list_is_empty(not_visited)) {
17061705
completed_scavenge(gcstate);
17071706
}
@@ -1736,7 +1735,6 @@ gc_collect_full(PyThreadState *tstate,
17361735
completed_scavenge(gcstate);
17371736
_PyGC_ClearAllFreeLists(tstate->interp);
17381737
validate_spaces(gcstate);
1739-
add_stats(gcstate, 2, stats);
17401738
}
17411739

17421740
/* This is the main function. Read this to understand how the
@@ -1846,10 +1844,11 @@ do_gc_callback(GCState *gcstate, const char *phase,
18461844
assert(PyList_CheckExact(gcstate->callbacks));
18471845
PyObject *info = NULL;
18481846
if (PyList_GET_SIZE(gcstate->callbacks) != 0) {
1849-
info = Py_BuildValue("{sisnsn}",
1847+
info = Py_BuildValue("{sisnsnsd}",
18501848
"generation", generation,
18511849
"collected", stats->collected,
1852-
"uncollectable", stats->uncollectable);
1850+
"uncollectable", stats->uncollectable,
1851+
"duration", stats->duration);
18531852
if (info == NULL) {
18541853
PyErr_FormatUnraisable("Exception ignored while invoking gc callbacks");
18551854
return;
@@ -2080,15 +2079,15 @@ _PyGC_Collect(PyThreadState *tstate, int generation, _PyGC_Reason reason)
20802079
if (reason != _Py_GC_REASON_SHUTDOWN) {
20812080
invoke_gc_callback(gcstate, "start", generation, &stats);
20822081
}
2083-
PyTime_t t1;
20842082
if (gcstate->debug & _PyGC_DEBUG_STATS) {
20852083
PySys_WriteStderr("gc: collecting generation %d...\n", generation);
2086-
(void)PyTime_PerfCounterRaw(&t1);
20872084
show_stats_each_generations(gcstate);
20882085
}
20892086
if (PyDTrace_GC_START_ENABLED()) {
20902087
PyDTrace_GC_START(generation);
20912088
}
2089+
PyTime_t start, stop;
2090+
(void)PyTime_PerfCounterRaw(&start);
20922091
PyObject *exc = _PyErr_GetRaisedException(tstate);
20932092
switch(generation) {
20942093
case 0:
@@ -2103,6 +2102,9 @@ _PyGC_Collect(PyThreadState *tstate, int generation, _PyGC_Reason reason)
21032102
default:
21042103
Py_UNREACHABLE();
21052104
}
2105+
(void)PyTime_PerfCounterRaw(&stop);
2106+
stats.duration = PyTime_AsSecondsDouble(stop - start);
2107+
add_stats(gcstate, generation, &stats);
21062108
if (PyDTrace_GC_DONE_ENABLED()) {
21072109
PyDTrace_GC_DONE(stats.uncollectable + stats.collected);
21082110
}
@@ -2124,12 +2126,9 @@ _PyGC_Collect(PyThreadState *tstate, int generation, _PyGC_Reason reason)
21242126
_Py_atomic_store_int(&gcstate->collecting, 0);
21252127

21262128
if (gcstate->debug & _PyGC_DEBUG_STATS) {
2127-
PyTime_t t2;
2128-
(void)PyTime_PerfCounterRaw(&t2);
2129-
double d = PyTime_AsSecondsDouble(t2 - t1);
21302129
PySys_WriteStderr(
21312130
"gc: done, %zd unreachable, %zd uncollectable, %.4fs elapsed\n",
2132-
stats.collected + stats.uncollectable, stats.uncollectable, d
2131+
stats.collected + stats.uncollectable, stats.uncollectable, stats.duration
21332132
);
21342133
}
21352134

‎Python/gc_free_threading.c‎

Lines changed: 13 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -1911,7 +1911,7 @@ handle_resurrected_objects(struct collection_state *state)
19111911
static void
19121912
invoke_gc_callback(PyThreadState *tstate, const char *phase,
19131913
int generation, Py_ssize_t collected,
1914-
Py_ssize_t uncollectable)
1914+
Py_ssize_t uncollectable, double duration)
19151915
{
19161916
assert(!_PyErr_Occurred(tstate));
19171917

@@ -1925,10 +1925,11 @@ invoke_gc_callback(PyThreadState *tstate, const char *phase,
19251925
assert(PyList_CheckExact(gcstate->callbacks));
19261926
PyObject *info = NULL;
19271927
if (PyList_GET_SIZE(gcstate->callbacks) != 0) {
1928-
info = Py_BuildValue("{sisnsn}",
1928+
info = Py_BuildValue("{sisnsnsd}",
19291929
"generation", generation,
19301930
"collected", collected,
1931-
"uncollectable", uncollectable);
1931+
"uncollectable", uncollectable,
1932+
"duration", duration);
19321933
if (info == NULL) {
19331934
PyErr_FormatUnraisable("Exception ignored while "
19341935
"invoking gc callbacks");
@@ -2340,7 +2341,6 @@ gc_collect_main(PyThreadState *tstate, int generation, _PyGC_Reason reason)
23402341
{
23412342
Py_ssize_t m = 0; /* # objects collected */
23422343
Py_ssize_t n = 0; /* # unreachable objects that couldn't be collected */
2343-
PyTime_t t1 = 0; /* initialize to prevent a compiler warning */
23442344
GCState *gcstate = &tstate->interp->gc;
23452345

23462346
// gc_collect_main() must not be called before _PyGC_Init
@@ -2372,19 +2372,19 @@ gc_collect_main(PyThreadState *tstate, int generation, _PyGC_Reason reason)
23722372
GC_STAT_ADD(generation, collections, 1);
23732373

23742374
if (reason != _Py_GC_REASON_SHUTDOWN) {
2375-
invoke_gc_callback(tstate, "start", generation, 0, 0);
2375+
invoke_gc_callback(tstate, "start", generation, 0, 0, 0);
23762376
}
23772377

23782378
if (gcstate->debug & _PyGC_DEBUG_STATS) {
23792379
PySys_WriteStderr("gc: collecting generation %d...\n", generation);
23802380
show_stats_each_generations(gcstate);
2381-
// ignore error: don't interrupt the GC if reading the clock fails
2382-
(void)PyTime_PerfCounterRaw(&t1);
23832381
}
23842382

23852383
if (PyDTrace_GC_START_ENABLED()) {
23862384
PyDTrace_GC_START(generation);
23872385
}
2386+
PyTime_t start, stop;
2387+
(void)PyTime_PerfCounterRaw(&start);
23882388

23892389
PyInterpreterState *interp = tstate->interp;
23902390

@@ -2399,13 +2399,13 @@ gc_collect_main(PyThreadState *tstate, int generation, _PyGC_Reason reason)
23992399
m = state.collected;
24002400
n = state.uncollectable;
24012401

2402+
(void)PyTime_PerfCounterRaw(&stop);
2403+
double duration = PyTime_AsSecondsDouble(stop - start);
2404+
24022405
if (gcstate->debug & _PyGC_DEBUG_STATS) {
2403-
PyTime_t t2;
2404-
(void)PyTime_PerfCounterRaw(&t2);
2405-
double d = PyTime_AsSecondsDouble(t2 - t1);
24062406
PySys_WriteStderr(
24072407
"gc: done, %zd unreachable, %zd uncollectable, %.4fs elapsed\n",
2408-
n+m, n, d);
2408+
n+m, n, duration);
24092409
}
24102410

24112411
// Clear the current thread's free-list again.
@@ -2426,6 +2426,7 @@ gc_collect_main(PyThreadState *tstate, int generation, _PyGC_Reason reason)
24262426
stats->collections++;
24272427
stats->collected += m;
24282428
stats->uncollectable += n;
2429+
stats->duration += duration;
24292430

24302431
GC_STAT_ADD(generation, objects_collected, m);
24312432
#ifdef Py_STATS
@@ -2444,7 +2445,7 @@ gc_collect_main(PyThreadState *tstate, int generation, _PyGC_Reason reason)
24442445
}
24452446

24462447
if (reason != _Py_GC_REASON_SHUTDOWN) {
2447-
invoke_gc_callback(tstate, "stop", generation, m, n);
2448+
invoke_gc_callback(tstate, "stop", generation, m, n, duration);
24482449
}
24492450

24502451
assert(!_PyErr_Occurred(tstate));

0 commit comments

Comments
 (0)
Back | FazBrowse Home | New Git URL