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

Poor performance on logging.RotatingFileHandler due to fix to #89564 #105623

Closed
zhatt opened this issue Jun 10, 2023 · 3 comments
Closed

Poor performance on logging.RotatingFileHandler due to fix to #89564 #105623

zhatt opened this issue Jun 10, 2023 · 3 comments
Labels
performance Performance or resource usage stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error

Comments

@zhatt
Copy link
Contributor

zhatt commented Jun 10, 2023

The fix to #89564 produced a significant performance degradation when logs are on an NFS filesystem. The fix for #89564 was for a bug found with the TimedRotatingFileHandler but an fix was added to the sized base file rotator too.

Here is the RotatingFileHandler.shouldRollover() function. The os.path.exists() and os.path.isfile() are very slow on NFS filesystems. On Linux systems, if os.path.isfile() returns False, the self.stream.seek(0,2) will always return 0 because the file is not seekable so non-isfile() files will never be rotated unless the rotation size is smaller than the message size.

Since, the rollover could be triggered with a very large msg and small maxBytes. Moving the exists() and isfile() check to inside the if self.stream.tell()... would cover that case and not run the expensive status operations with a correctly configured logger except when the rotation is needed. That is similar to the fix made to the TimedRotatingFileHandler in #96159.

    def shouldRollover(self, record):
        """
        Determine if rollover should occur.

        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
        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:
                return True
        return False

Linked PRs

@zhatt zhatt added the type-bug An unexpected behavior, bug, or error label Jun 10, 2023
@AlexWaygood AlexWaygood added performance Performance or resource usage stdlib Python modules in the Lib dir labels Jun 10, 2023
@arhadthedev
Copy link
Member

cc @vstinner as an author of the linked issue gh-89564 and @vsajip as an author of its associated PR.

@vstinner
Copy link
Member

vstinner commented Jun 13, 2023

Do you want to propose a fix? (Pull request)

@zhatt
Copy link
Contributor Author

zhatt commented Jun 16, 2023

@vstinner I will create a PR.

zhatt added a commit to zhatt/cpython that referenced this issue Jun 17, 2023
…ndler

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.
zhatt added a commit to zhatt/cpython that referenced this issue Jun 17, 2023
…ndler

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.
zhatt added a commit to zhatt/cpython that referenced this issue Jun 17, 2023
zhatt added a commit to zhatt/cpython that referenced this issue Jun 20, 2023
zhatt added a commit to zhatt/cpython that referenced this issue Jul 13, 2023
zhatt added a commit to zhatt/cpython that referenced this issue Jun 27, 2024
serhiy-storchaka pushed a commit that referenced this issue Jun 27, 2024
…H-105887)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
miss-islington pushed a commit to miss-islington/cpython that referenced this issue Jun 28, 2024
…ndler (pythonGH-105887)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

(cherry picked from commit e9b4ec6)

Co-authored-by: Craig Robson <craig@zhatt.com>
Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
miss-islington pushed a commit to miss-islington/cpython that referenced this issue Jun 28, 2024
…ndler (pythonGH-105887)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

(cherry picked from commit e9b4ec6)

Co-authored-by: Craig Robson <craig@zhatt.com>
Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
serhiy-storchaka pushed a commit that referenced this issue Jun 28, 2024
…andler (GH-105887) (GH-121116)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

(cherry picked from commit e9b4ec6)

Co-authored-by: Craig Robson <craig@zhatt.com>
Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
serhiy-storchaka pushed a commit that referenced this issue Jun 28, 2024
…andler (GH-105887) (GH-121117)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

(cherry picked from commit e9b4ec6)

Co-authored-by: Craig Robson <craig@zhatt.com>
Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
mrahtz pushed a commit to mrahtz/cpython that referenced this issue Jun 30, 2024
…ndler (pythonGH-105887)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
noahbkim pushed a commit to hudson-trading/cpython that referenced this issue Jul 11, 2024
…ndler (pythonGH-105887)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
estyxx pushed a commit to estyxx/cpython that referenced this issue Jul 17, 2024
…ndler (pythonGH-105887)

The check for whether the log file is a real file is expensive on NFS
filesystems.  This commit reorders the rollover condition checking to
not do the file type check if the expected file size is less than the
rotation threshold.

Co-authored-by: Oleg Iarygin <oleg@arhadthedev.net>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
performance Performance or resource usage stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error
Projects
Development

No branches or pull requests

5 participants