Page MenuHomePhabricator

RotatingFileHandler.doRollover() does not increase the backup count right
Closed, ResolvedPublicBUG REPORT

Description

List of steps to reproduce (step by step, including full links if applicable):

  • Run a script with -log enabled

What happens?:
If the file maximum size is exceeded only backup files with <scriptname>.1.log and <scriptname>.99.log are created where 1.log is newer than 99.log.

What should have happened instead?:

def doRollover(self):
    """Modified naming system for logging files.

    Overwrites the default Rollover renaming by inserting the count
    number between file name root and extension. If backupCount is
    >= 1, the system will successively create new files with the
    same pathname as the base file, but with inserting ".1", ".2"
    etc. in front of the filename suffix. For example, with a
    backupCount of 5 and a base file name of "app.log", you would
    get "app.log", "app.1.log", "app.2.log", ... through to
    "app.5.log". The file being written to is always "app.log" -
    when it gets filled up, it is closed and renamed to "app.1.log",
    and if files "app.1.log", "app.2.log" etc. already exist, then
    they are renamed to "app.2.log", "app.3.log" etc. respectively.

    If backupCount is == -1 do not rotate but create new numbered
    filenames. The newest file has the highest number except some
    older numbered files where deleted and the bot was restarted.
    In this case the ordering starts from the lowest available
    (unused) number.
    """

Background
config.py setting is:

# Number of rotating logfiles are created. The older files get the higher
# number. If logfilecount is 0, no logfile will be archived but the current
# logfile will be overwritten if the file size reached the logfilesize above.
# If logfilecount is -1 there are no rotating logfiles but the files where
# renamed if the logfile is full. The newest file gets the highest number until
# some logfiles where deleted.
############## LOGFILE SETTINGS ##############
log = ['*']
logfilesize = 4096
logfilecount = 99

Event Timeline

Xqt triaged this task as Medium priority.Jul 3 2021, 5:46 PM
Xqt updated the task description. (Show Details)

This is a Windows issue, see https://bugs.python.org/issue25121. Seems that setting the same file_handler to root_logger, debug_logger and warnings_logger causes that error. A PermissionError is raised when renaming the .log file to 1.log inside rotate() method. Comment them out in bot.py the rotating works as expected:

##        for component in config.debug_log:
##            if component:
##                debuglogger = logging.getLogger('pywiki.' + component)
##            else:
##                debuglogger = logging.getLogger('pywiki')
##            debuglogger.setLevel(DEBUG)
##            debuglogger.addHandler(file_handler)
##
##        warnings_logger.addHandler(file_handler)

Change 703402 had a related patch set uploaded (by Xqt; author: Xqt):

[pywikibot/core@master] [bugfix] Rewrite init_handlers and RotatingFileHandler

https://gerrit.wikimedia.org/r/703402

Change 703402 abandoned by Xqt:

[pywikibot/core@master] [bugfix] Rewrite init_handlers and RotatingFileHandler

Reason:

done wih other patches, T286127 isn't solved here, see task

https://gerrit.wikimedia.org/r/703402

Xqt raised the priority of this task from Medium to High.Apr 28 2022, 4:40 AM

Change 787456 had a related patch set uploaded (by Xqt; author: Xqt):

[pywikibot/core@master] [bugfix] close handler before deleting it

https://gerrit.wikimedia.org/r/787456

Change 787456 abandoned by Xqt:

[pywikibot/core@master] [bugfix] close handler before deleting it

Reason:

https://gerrit.wikimedia.org/r/787456

Change 787457 had a related patch set uploaded (by Xqt; author: Xqt):

[pywikibot/core@master] [bugfix] close handlers before deleting it

https://gerrit.wikimedia.org/r/787457

Xqt claimed this task.

Change 787457 merged by jenkins-bot:

[pywikibot/core@master] [bugfix] close handlers before deleting them

https://gerrit.wikimedia.org/r/787457