python / python/cpython

test_rollover_based_on_st_birthtime_only fails on slow CI: rotated file is outside the fixed 5-second search window

Đang mở
#157,161 0 bình luận 0 reaction 0 người được giao Xem trên GitHub

Chưa có ai nhận issue này.

tests
Ngôn ngữ chính
Python
Star
77.2k
Fork
35.9k
Chỉ số merge pull request
Chỉ số pull request đang chờ

Mô tả

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

Hướng dẫn đóng góp

Mở hướng dẫn đóng góp

Bắt đầu từ đâu

  1. Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
  2. Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
  3. Fork repository và làm thay đổi trên một nhánh.
  4. Mở pull request có tham chiếu số hiệu của issue.

Hướng nghiên cứu

Bắt đầu với test_rollover_based_on_st_birthtime_only trong test.test_logging.TimedRotatingFileHandlerTest và tái hiện nó trên cấu hình CI của Windows. Xem lại cách bài kiểm thử tìm các tệp đã rollover dựa trên thời gian được ghi nhận của nó và xác minh hành vi rollover hiện có. Công việc được hoàn tất khi bài kiểm thử vẫn đáng tin cậy nếu quá trình thiết lập và phát sinh đầu ra mất nhiều thời gian hơn dự kiến, đồng thời vẫn phát hiện đúng tệp đã rollover.

Do mô hình lập chỉ mục viết ra từ nội dung của issue.

Đánh giá

Công nghệ
python
Lĩnh vực
testing-qa
Loại issue
Lỗi
Độ khó
2/5
Thời gian dự kiến
1-3 giờ
Mức độ hoạt động
Đình trệ
Độ rõ ràng
Đặc tả rõ ràng
Mức phù hợp với người mới
35/100

Nhận issue mới trong hộp thư của bạn

Bản tóm tắt ngắn những issue GitHub phù hợp với người mới.