GV

GeezerVison

The World Wide Web, restored to 800 pixels of glory.

Home|About|Gaming cabinet|Archives|How it works|Starter sites

On this site

  • Sign in
  • ActionsCI/CD and automation
  • CodespacesCloud development environments
  • All Features
  • Documentation
  • Training
  • Certifications
  • Build with Copilot
  • Customize Copilot
  • Integrations
  • Trending repos
  • GitHub Sponsors
  • Developer articles
  • Enterprises

This view

  • Original page
  • New address

GeezerVison is showing github.com — gh-157161: Fix test_rollover_based_on_st_birthtime_only on slow machines by iamsharduld · Pull Request #157162 · python/cpython

Conversation

@iamsharduld

@iamsharduld iamsharduld commented Sep 8, 2026 •
edited by bedevere-app Bot
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Contributor

The test looks for the rotated file by trying the timestamps of the last 5 seconds. The rotated file is named after the creation time of the log file (rolloverAt - interval, where rolloverAt was computed from the file's creation time), so it can only be found if the whole test took less than 5 seconds. Its nominal duration is 4.2 seconds of sleeps plus three handler set-ups, and on the failing CI job (diagnostics quoted in the issue) it took 6.07 seconds, so the file named after second 45 was never checked from second 51.

This derives the search window from the time the test actually took, plus two seconds: one because the log file is created in setUp(), slightly before the test starts, and one for the one-second resolution of the names.

Verified:

  • With a 1.2 s slowdown injected into each add_record() (a 7.8 s test), the current test fails with exactly the CI message, No rotated files found, went back 5 seconds; with this change it passes.
  • Without the slowdown it passes repeatedly, and the whole test_logging module passes with -u walltime.

The June change in GH-150954 widened the window by one timestamp; this makes it follow the actual duration so that no fixed value needs to be tuned again.

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

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions
@iamsharduld
pythongh-157161: Fix test_rollover_based_on_st_birthtime_only on slow…
34d838a 
… machines

The rotated file is named after the creation time of the log file, but
the test only looked for it within a fixed 5 seconds before the end of
the test. On a slow CI runner the test took 6 seconds, so the file was
found nowhere and the test failed although the rollover was correct.

Derive the search window from the time the test actually took.
@iamsharduld
iamsharduld requested a review from vsajip as a code owner September 8, 2026 04:46
@bedevere-app bedevere-app Bot mentioned this pull request Sep 8, 2026
test_rollover_based_on_st_birthtime_only fails on slow CI: rotated file is outside the fixed 5-second search window #157161
Open
@bedevere-app bedevere-app Bot added tests Tests in the Lib/test dir awaiting review labels Sep 8, 2026
@iamsharduld iamsharduld mentioned this pull request Sep 8, 2026
gh-157184: Scale the join() alarm in the multiprocessing kill tests #157185
Closed
brittanyrey
brittanyrey reviewed Sep 8, 2026
View reviewed changes
Comment thread Lib/test/test_logging.py Outdated
now = datetime.datetime.now()
GO_BACK = 5 # seconds
for secs in range(GO_BACK + 1):
go_back = int((now - start).total_seconds()) + 2

@brittanyrey brittanyrey Sep 8, 2026 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Contributor

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it make sense to include an inline comment on how this number is derived?
edit: or maybe rename s/go_back/total_time_spent (total_test_time, test_duration)

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions

@iamsharduld iamsharduld Sep 9, 2026

Copy link
Copy Markdown
Contributor Author

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point, done. The window is now built in two named steps: test_duration from the measured elapsed time, then oldest = test_duration + 2, with a comment saying where the two seconds come from (the log file is created in setUp(), a moment before the test starts, and the suffix has a one second resolution).

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions
Comment thread Lib/test/test_logging.py Outdated
GO_BACK = 5 # seconds
for secs in range(GO_BACK + 1):
go_back = int((now - start).total_seconds()) + 2
for secs in range(go_back + 1):

@brittanyrey brittanyrey Sep 8, 2026

Copy link
Copy Markdown
Contributor

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why add 2 on the line above, just to add 1 here?

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions

@iamsharduld iamsharduld Sep 9, 2026

Copy link
Copy Markdown
Contributor Author

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

They were doing two different jobs, which is exactly why it read badly. The + 2 is the margin described above; the + 1 only makes range() cover oldest itself, since it is exclusive. The margin now has its own named variable and the loop carries an # inclusive of oldest comment, so neither number is bare arithmetic any more.

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions
@iamsharduld
Address review: name the margin and explain the two additions
dffb770 
Split the search window into the measured duration of the test and an
explicit two second margin, and note that the range covers the oldest
second as well.
@iamsharduld

iamsharduld commented Sep 9, 2026

Copy link
Copy Markdown
Contributor Author

I have made the requested changes; please review again
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@bedevere-app bedevere-app Bot added awaiting change review and removed awaiting review labels Sep 9, 2026
@bedevere-app

bedevere-app Bot commented Sep 9, 2026

Copy link
Copy Markdown

Thanks for making the requested changes!

: please review the changes made to this pull request.
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@iamsharduld
Remove the NEWS entry
4e22320
@iamsharduld

iamsharduld commented Sep 9, 2026 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Contributor Author

Dropped the NEWS entry: this changes only tests, which the devguide lists among the exemptions. The same point was made on #157171 ("This is a fix to unreleased test. It does not need a NEWS entry") and on #157158, so I am applying it across my open test-only PRs rather than having it raised on each one. bedevere/news will stay red until skip news is applied.

(Edited to remove two user mentions that pinged core developers for no reason. Sorry for the noise.)
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@brittanyrey brittanyrey brittanyrey left review comments
@vsajip vsajip Awaiting requested review from vsajip vsajip is a code owner

Uh oh!

There was an error while loading. Please reload this page.

Assignees

No one assigned

Labels

awaiting change review tests Tests in the Lib/test dir

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

Uh oh!

There was an error while loading. Please reload this page.

2 participants

@iamsharduld @brittanyrey
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.
You are visitor 01402520 — GeezerVison does not store the pages you look up.
Best viewed with Netscape Navigator 4.7 or Internet Explorer 6 at 800×600. No cookies required.