Repository navigation
Conversation
…onometers Signed-off-by: Sergey Vasilyev <nolar@nolar.info>
nolar
referenced
this pull request
in nolar/kopf
Oct 5, 2026
Due to new three tests, another completely unrelated test (`test_threadsafe_indeed_works()`) started to fail unusually: only in Python 3.12 full-auth; works fine in other 3.12 modes and other full-auth versions — but 100% reproducible in CI and in CI only (not locally). Experiments have shown that the issue happens only when all three tests are active (1+2+3), while the test run passes with only one or two tests (1+2, 2+3, 1+3). Time measurements indicated that the extra time (≈0.13s) was spent on operations so routine that they were not even suspected: exiting a function or adding an item to a list, not in the actual thread starting or something resource-intense. Besides, simple time measurements themselves caused the tests to pass sometimes. The only suspicion was that something was happening under the hood at these moments, and the garbage collection was the number one candidate (in the absence of any parallel/concurrent activities). Probably, the amount of garbage accumulated from all tests was anyway huge, and adding three more tests pushed it beyond the threshold, which accidentally caused the garbage collection in these particular real-clock tests (previously, probably happened in other tests that did not notice anything). Just a sequence of accidents. Either way, enforcing the garbage collection before the test and disabling the garbage collection during the real-clock tests fixed the issue. Pure luck. Signed-off-by: Sergey Vasilyev <nolar@nolar.info>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Caused by a fancy bug in Kopf's test suite, where there were extra 0.13 seconds in one real-clock test after adding three new completely unrelated tests somewhat 50-100 tests eariler in the test run. The suspicion was that it accidentally triggered the garbage collection precisely during the duration of the time measurement — there was a function exit in it, which is a trigger for gc in CPython; the extra time was measurered exactly at function exit. The theory was not fully proven, but disabling the gc helped to either fix the issue, or to move that extra time earlier/later outside of the chronometer.
All in all, for the sake of proper precise time measurements — as intended by the chronometers — all side activities, such as garbage collection, should be suppressed during the measured code block. There is a way to opt out:
keep_gc=True.For clarity: it is not proven that the issue was caused by garbage collection, it is just the most viable explanation. It is also not proven that disabling the gc actually fixed the issue. As experiments show, the mere
import gcon the module level already fixed the bug — probably by shifting the gc point earlier/later but outside of the chronometer. Even a switch to looptime's wip branch, which also fixes the issue, might actually fix it becauseimport gchappens deep there and changes the balance. However, let this "fix" be — as it at least seems viable, despite unproven.