GeezerVison is showing github.com — Negative GC gen0 count in free threaded python delaying GC · Issue #142048 · python/cpython
Negative GC gen0 count in free threaded python delaying GC #142048Labels 3.13only security fixesonly security fixes3.14bugs and security fixesbugs and security fixes3.15bugs and security fixesbugs and security fixesinterpreter-core(Objects, Python, Grammar, and Parser dirs)(Objects, Python, Grammar, and Parser dirs)topic-free-threadingtype-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error DescriptionBug report
Bug description:
I suspect there might be a bug in the garbage collector under free threading. If I run this script
import gc
import threading
import time
def worker():
while not stop.is_set():
_ = [dict(x=i) for i in range(1000)]
stop = threading.Event()
threads = [threading.Thread(target=worker) for _ in range(8)]
for t in threads:
t.start()
time.sleep(2)
stop.set()
for t in threads:
t.join()
gen0 = gc.get_count()[0]
print(f"gen0 = {gen0}")
assert gen0 >= 0the assertion fails.
We observe in our full application that gen0 is quite negative, less than -10000 at times. The net effect of this is that garbage collection runs less frequently than it otherwise might, resulting in large GC pauses in our application (~3s). This doesn't seem to result in any functional problems aside from much longer stop-the-world pauses than ideal.
This seems to repro even if I set PYTHON_GIL=1 but not against an older version of python (3.10.12). I'm thus not completely sure if this is intended or not. It seems semantically ok for gen0 to go negative, like if deallocations exceed allocations that doesn't seem wrong, but is it supposed to?
I have reproduced this with 3.14t and cpython built against main.
CPython versions tested on:
3.14
Operating systems tested on:
Linux
Linked PRs
Activitychanged the title [-]GC gen0 count goes negative in free threaded python[/-] [+]Negative GC gen0 count in free threaded python delaying GC[/+] on Nov 28, 2025kevmo314 commented on Nov 28, 2025 ContributorAuthor More actions colesbury commented on Dec 1, 2025 Yes, it was intentional. Can you provide some GC logs? kevmo314 commented on Dec 1, 2025 ContributorAuthor More actions @colesbury Here's some timing logs that we pulled from the garbage collector callback.
[2025-12-01 19:13:21] [GC] Starting generation 2 collection
[2025-12-01 19:13:21] [GC] Generation 2 finished in 187.07ms: 339881 collected, 0 uncollectable | counts: gen0=-416431, gen1=0, gen2=0
[2025-12-01 19:13:27] [GC] Starting generation 0 collection
[2025-12-01 19:13:27] [GC] Generation 0 finished in 57.14ms: 6588 collected, 0 uncollectable | counts: gen0=-7177, gen1=16, gen2=0
[2025-12-01 19:13:27] [GC] Starting generation 0 collection
[2025-12-01 19:13:27] [GC] Generation 0 finished in 60.33ms: 0 collected, 0 uncollectable | counts: gen0=173, gen1=17, gen2=0
[2025-12-01 19:13:27] [GC] Starting generation 0 collection
[2025-12-01 19:13:28] [GC] Generation 0 finished in 81.09ms: 0 collected, 0 uncollectable | counts: gen0=-2, gen1=18, gen2=0
[2025-12-01 19:13:34] [GC] Starting generation 2 collection
[2025-12-01 19:13:34] [GC] Generation 2 finished in 112.93ms: 6666 collected, 0 uncollectable | counts: gen0=-7517, gen1=0, gen2=0
[2025-12-01 19:14:03] [GC] Starting generation 0 collection
[2025-12-01 19:14:03] [GC] Generation 0 finished in 250.81ms: 231437 collected, 0 uncollectable | counts: gen0=-279325, gen1=1, gen2=0
[2025-12-01 19:14:36] [GC] Starting generation 0 collection
[2025-12-01 19:14:37] [GC] Generation 0 finished in 298.12ms: 305273 collected, 0 uncollectable | counts: gen0=-362465, gen1=2, gen2=0
[2025-12-01 19:15:18] [GC] Starting generation 0 collection
[2025-12-01 19:15:19] [GC] Generation 0 finished in 391.81ms: 379195 collected, 0 uncollectable | counts: gen0=-446220, gen1=3, gen2=0
[2025-12-01 19:16:07] [GC] Starting generation 0 collection
[2025-12-01 19:16:08] [GC] Generation 0 finished in 462.31ms: 450402 collected, 0 uncollectable | counts: gen0=-526494, gen1=4, gen2=0
[2025-12-01 19:17:05] [GC] Starting generation 0 collection
[2025-12-01 19:17:05] [GC] Generation 0 finished in 492.43ms: 524910 collected, 0 uncollectable | counts: gen0=-610764, gen1=5, gen2=0
The first few ~100ms logs are unproblematic. As we keep running the server, the gap between collections keeps growing, gen0 becomes more and more negative, and the time per collection keeps growing, resulting in large pauses in our server. colesbury commented on Dec 1, 2025 Ugh, yeah this is really broken. Even this simple program just keeps slowing down with every collection:
import gc
gc.set_debug(gc.DEBUG_STATS)
def main():
while True:
trash = {}
trash['trash'] = trash
if __name__ == "__main__":
main()I think the problem is that we are decreasing gcstate.young.count for all the objects freed during the collection. So we don't do a collection until we allocate at least that many objects plus the computed threshold.
I think we can either:
- Set
state->gcstate->young.count to 0 at the end of gc_collect_internal
- Or don't let it become negative as you suggest (i.e., use a compare-exchange loop in
record_deallocation)
cc @nascheme kevmo314 commented on Dec 1, 2025 ContributorAuthor More actions Out of my personal curiosity,
use a compare-exchange loop in record_deallocation
How does one do this without a bunch of thread contention? It seems difficult to do with the atomics available to us. colesbury commented on Dec 1, 2025 The counts are buffered in thread local state to reduce thread contention. We only update the shared variable when the count exceeds +/-LOCAL_ALLOC_COUNT_THRESHOLD (+/-512).
The atomic add is probably a little bit faster, but otherwise there's not much of a difference between the compare-exchange and atomic add. If you have thread contention with the compare-exchange, you'll probably also have it with the atomic add too.
static void
record_deallocation(PyThreadState *tstate)
{
struct _gc_thread_state *gc = &((_PyThreadStateImpl *)tstate)->gc;
gc->alloc_count--;
if (gc->alloc_count <= -LOCAL_ALLOC_COUNT_THRESHOLD) {
GCState *gcstate = &tstate->interp->gc;
int count = _Py_atomic_load_int_relaxed(&gcstate->young.count);
int new_count;
do {
if (count == 0){
break;
}
new_count = count + (int)gc->alloc_count;
if (new_count < 0) {
new_count = 0;
}
} while (!_Py_atomic_compare_exchange_int(&gcstate->young.count,
&count,
new_count));
gc->alloc_count = 0;
}
}kevmo314 commented on Dec 1, 2025 ContributorAuthor More actions Makes sense! I updated #142051 with that approach, I'll test it out as well but it seems reasonable to me. StanFromIreland commented on Dec 3, 2025 Triage: Can this be closed? colesbury commented on Dec 3, 2025
MetadataMetadata3.13only security fixesonly security fixes3.14bugs and security fixesbugs and security fixes3.15bugs and security fixesbugs and security fixesinterpreter-core(Objects, Python, Grammar, and Parser dirs)(Objects, Python, Grammar, and Parser dirs)topic-free-threadingtype-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error DevelopmentNo branches or pull requestsIssue actions
|