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.

Sign up for GitHub

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-105623 Fix performance degradation in logging RotatingFileHandler #105887

Merged
merged 7 commits into from
Jun 27, 2024
Merged

gh-105623 Fix performance degradation in logging RotatingFileHandler #105887

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
d3a1875
gh-105623 Fix performance degradation in logging RotatingFileHandler
zhatt Jun 17, 2023
b1d5ba1
Merge branch 'main' into gh-105623
zhatt Jun 17, 2023
84ad7d8
Update Misc/NEWS.d/next/Library/2023-06-17-09-07-06.gh-issue-105623.5…
zhatt Jun 18, 2023
a677f11
Merge branch 'main' into gh-105623
zhatt Jun 20, 2023
e3ee1d7
Merge branch 'main' into gh-105623
zhatt Jul 13, 2023
3ff1523
Merge branch 'main' into gh-105623
serhiy-storchaka Mar 3, 2024
7b5189b
Merge branch 'main' into gh-105623
zhatt Jun 27, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 3 additions & 3 deletions Lib/logging/handlers.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -193,15 +193,15 @@ def shouldRollover(self, record):
Basically, see if the supplied record would cause the file to exceed
the size limit we have.
"""
# See bpo-45401: Never rollover anything other than regular files
if os.path.exists(self.baseFilename) and not os.path.isfile(self.baseFilename):
return False
Comment on lines -196 to -198
Copy link
Contributor

Choose a reason for hiding this comment

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

Even with a local file-system this is a substantive chunk of the run time

Screenshot 2023-07-12 at 6 22 51 PM

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@bdraco I'm not familiar with the report generated by py-spy. Are you seeing that the os.path.exists() and os.path.isfile() are expensive or the self.format()? The self.format() is probably a different bug that needs fixed since rollover is formatting the message once to get its length and then emit later formats it again.

Copy link
Contributor

@bdraco bdraco Jul 13, 2023 •
edited
Loading

Choose a reason for hiding this comment

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

I'd expect the format and emit to be expensive here (relatively ... the logger is quite busy). What is unexpected is the cost of os.path.exists and os.path.isfile which is solved by this PR.

Sorry for the lack of clarity. This looks like a good fix and I wanted to point out the problem is not limited to NFS.

Copy link
Member

Choose a reason for hiding this comment

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

Under normal usage, self.baseFilename doesn't change. Perhaps we just cache the result of the existence/is-file test when we open the file? Wouldn't that be a better approach?

if self.stream is None: # delay was set...
self.stream = self._open()
if self.maxBytes > 0: # are we rolling over?
msg = "%s\n" % self.format(record)
self.stream.seek(0, 2) #due to non-posix-compliant Windows feature
if self.stream.tell() + len(msg) >= self.maxBytes:
# See bpo-45401: Never rollover anything other than regular files
if os.path.exists(self.baseFilename) and not os.path.isfile(self.baseFilename):
return False
return True
return False

Expand Down
2 changes: 2 additions & 0 deletions Misc/NEWS.d/next/Library/2023-06-17-09-07-06.gh-issue-105623.5G06od.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
Fix performance degradation in
:class:`logging.handlers.RotatingFileHandler`. Patch by Craig Robson.
Loading