test_rollover_based_on_st_birthtime_only fails on slow CI: rotated file is outside the fixed 5-second search window
Nessuno ha ancora preso questa issue.
- Lingua principale
- Python
- Stelle
- 77.2k
- Fork
- 35.9k
- Metriche di merge delle PR
- Metriche PR in attesa
Descrizione
Bug report
Bug description:
test_rollover_based_on_st_birthtime_only failed again on main, on the "Windows / Build and test (x64, tail-call)" CI job of 532b9dbd67 (2026-09-01): https://github.com/python/cpython/actions/runs/33523218872/job/99907492032
FAIL: test_rollover_based_on_st_birthtime_only (test.test_logging.TimedRotatingFileHandlerTest.test_rollover_based_on_st_birthtime_only)
AssertionError: False is not true : No rotated files found, went back 5 seconds
This is the test that gh-150960 (fixed by GH-150954, which widened the search from 5 to 6 timestamps) was about. The diagnostics the test prints show why it still fails on a slow machine:
Test time: 2026-09-01 15-10-51
The only matching files are: ['test_logging-2-p8i89g4b.log', 'test_logging-2-p8i89g4b.log.2026-09-01_15-10-45']
Contents of test_logging-2-p8i89g4b.log:
2026-09-01 15:10:51,079 testing - new record supposedly in the new file after rollover
Contents of test_logging-2-p8i89g4b.log.2026-09-01_15-10-45:
2026-09-01 15:10:45,004 testing - initial
2026-09-01 15:10:47,105 testing - update before rollover to renew the st_mtime
The rollover happened and is correct. The rotated file is named after the start of the interval, which is the creation time of the log file (TimedRotatingFileHandler.__init__() computes rolloverAt from min(creation_time, modification_time), and doRollover() uses rolloverAt - interval for the suffix), so its suffix is 15-10-45. The test then looks for a rotated file with a timestamp between now and now - 5 s. now was 15:10:51, six seconds after the file was created, because the third add_record() came 3.97 s after the second one instead of about 2.1 s. So the file with suffix 15-10-45 was one second outside the window.
The test's timing (two time.sleep(2.1) calls plus three handler set-ups and emits) is nominally 4.2 s, and any slowdown of more than 0.8 s pushes the rotated file out of the fixed 5-second window. The window should be derived from the time the test actually took, since the suffix can never be older than the moment the log file was created.
CPython versions tested on:
CPython main branch
Operating systems tested on:
Windows (CI)
Linked PRs
- gh-157162
Guida per i contributori
Apri la guida per i contributori
Come iniziare
- Leggi tutta la issue e poi la guida ai contributi del progetto.
- Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
- Fai un fork del repository e lavora su un branch.
- Apri una pull request che faccia riferimento al numero della issue.
Direzione di ricerca
Inizia da test_rollover_based_on_st_birthtime_only in test.test_logging.TimedRotatingFileHandlerTest e riproducilo nella configurazione CI di Windows. Esamina il modo in cui il test cerca i file sottoposti a rollover rispetto all'ora registrata e verifica il comportamento di rollover esistente. Il lavoro è completato quando il test rimane affidabile se la configurazione e le emissioni richiedono più tempo del previsto, continuando comunque a rilevare il file sottoposto correttamente a rollover.
Scritto dal modello di indicizzazione a partire dal testo della issue.
Valutazione
- Stack tecnologico
- python
- Ambito
- testing-qa
- Tipo di issue
- Bug
- Difficoltà
- 2/5
- Tempo stimato
- 1-3 ore
- Stato di attività
- Ferma
- Chiarezza
- Specificata chiaramente
- Idoneità per principianti
- 35/100