Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

gh-84649: Make TimedRotatingFileHandler use CTIME instead of MTIME #24660

Open
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

martonivan
Copy link

@martonivan martonivan commented Feb 26, 2021

The TimedRotatingFileHandler previously used MTIME attribute of the log
file to detect whether it has to be rotate yet or not. In cases when the
file is changed within the rotation period the MTIME is also updated
to the current time and the rotation never happens. It's more
appropriate to check the file creation time (CTIME) instead.

https://bugs.python.org/issue40469

@the-knights-who-say-ni
Copy link

Hello, and thanks for your contribution!

I'm a bot set up to make sure that the project can legally accept this contribution by verifying everyone involved has signed the PSF contributor agreement (CLA).

CLA Missing

Our records indicate the following people have not signed the CLA:

@martonivan

For legal reasons we need all the people listed to sign the CLA before we can look at your contribution. Please follow the steps outlined in the CPython devguide to rectify this issue.

If you have recently signed the CLA, please wait at least one business day
before our records are updated.

You can check yourself to see if the CLA has been received.

Thanks again for the contribution, we look forward to reviewing it!

@martonivan
Copy link
Author

I've rebased the branch, squashed the recent fix (about the NEWS typo) into the last commit, as it was partially recommended in the bug report about the flawed testing infrastructure: https://bugs.python.org/issue43382

@github-actions
Copy link

github-actions bot commented Apr 4, 2021

This PR is stale because it has been open for 30 days with no activity.

@github-actions github-actions bot added the stale Stale PR or inactive for long period of time. label Apr 4, 2021
@vsajip
Copy link
Member

vsajip commented Sep 2, 2021

See my suggestion on the issue if you want to progress things further.

@martonivan
Copy link
Author

See my suggestion on the issue if you want to progress things further.

Thanks Vinay, I'll implement the suggested and acceptable solution as soon as I get there and will update this merge request.

MaxwellDupre

This comment was marked as outdated.

@github-actions github-actions bot removed the stale Stale PR or inactive for long period of time. label Aug 4, 2022
Copy link

cpython-cla-bot bot commented Mar 1, 2024

All commit authors signed the Contributor License Agreement.
CLA signed

Copy link
Member

@serhiy-storchaka serhiy-storchaka left a comment

Choose a reason for hiding this comment

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

LGTM. I was just about to create the same issue.

@serhiy-storchaka
Copy link
Member

@martonivan, the mechanism for the CLA signing was changed, please sign the CLA again, it is necessary for merging. Thank you for your contribution.

@erlend-aasland erlend-aasland changed the title bpo-40469: Make TimedRotatingFileHandler use CTIME instead of MTIME gh-84649: Make TimedRotatingFileHandler use CTIME instead of MTIME Mar 1, 2024
@serhiy-storchaka
Copy link
Member

serhiy-storchaka commented Mar 1, 2024

Well, it is complicated.

  1. First, there are failing tests. They change the modification time to trigger rollover (it is not easy to fake the creation time). It can be fixed if make the code taking the minimum of ctime and mtime.

  2. New tests for ctime are needed to test that old files are rolled over even if mtime is fresh. I see two ways:

    • Create a handler with very short interval (3 seconds), emit a log record, close the handler, wait 1.5 seconds, re-create the handler, emit the record, close the handler, check that the file was not rolled over, wait 1.5 seconds, re-create the handler, emit the record, close the handler, check that the file was rolled over. Exact times may need corrections. There may be surprises on Windows with FAT32.
    • Create a modification of one of currently failing tests. Instead changing the modification time to the past time, change it to the future time. You need also to patch time.time() to make it returning the time from future.

    It would be better to implement both ways.

  3. ctime is actually not the "creation time", but the "node change time", although in many cases there is no difference between them. But it is worth to use also the real creation time which is available on some platforms. It is exposed as the st_birthtime attribute (note that it is float). So perhaps the code should take the minimum os st_birthtime, st_ctime and st_mtime.

@martonivan
Copy link
Author

I've implemented many of the suggested changes, but realized a huge issue: on Linux, since ctime also changes when the data block changes (practically when mtime changes), the test that checks if only the birthdate is old enough for rotation will always fail. It would be nice the have statx implemented and birth date/creation date known there too, but this issue is already staling for a while: #19125
I could restrict this test only for Windows and MacOS, I guess. I didn't find the proper helper scripts yet in test/support, but I assume this could be a workaround until the PR mentioned above is not merged. What would you suggest? What's the best practice to resolve similar issues?

@serhiy-storchaka
Copy link
Member

It is okay if this part of the feature is not supported on all platforms. We should do the best of what is currently possible on every platform. The availability of these attributes also depends on the file system.

The TimedRotatingFileHandler previously only used st_mtime attribute of the
log file to detect whether it has to be rotate yet or not. In cases when the
file is changed within the rotatation period the st_mtime is also updated
to the current time and the rotation never happens.

It's more appropriate to check the file creation time (st_ctime) instead.
Whenever available, the more appropriate st_birthtime will be in use. (This
feature is available on FreeBSD, MacOS and Windows at the moment.) If
the st_mtime would be newer than st_ctime (e.g.: because the inode
related to the file has been changed without any file content
modification), then the earliest attribute will be used.
@martonivan
Copy link
Author

All the tests are green on the supported operating systems.

@erlend-aasland
Copy link
Contributor

erlend-aasland commented Mar 8, 2024

@martonivan: when sync'ing with main, could you instead please do git merge --no-ff main, and not git rebase? Force-pushes do not play very well with GitHub's UI, and it makes reviewing harder. See also the devguide. Note that all PRs are squashed into a single commit when we merge, so it does not matter if the PR commit history is messy.

@martonivan
Copy link
Author

@martonivan: when sync'ing with main, could you instead please do git merge --no-ff main, and not git rebase? Force-pushed do not play very well with GitHub's UI, and it makes reviewing harder. See also the devguide. Note that all PRs are squashed into a single commit when we merge, so it does not matter if the PR commit history is messy.

Noted for further contribution, I'm not sure if any further commits will be necessary for this one.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

10 participants