pythonlogginghandlers

The logging.handlers: How to rollover after time or maxBytes?


I do struggle with the logging a bit. I'd like to roll over the logs after certain period of time and also after reaching certain size.

Rollover after a period of time is made by TimedRotatingFileHandler, and rollover after reaching certain log size is made by RotatingFileHandler.

But the TimedRotatingFileHandler doesn't have the attribute maxBytes and the RotatingFileHandler can not rotate after a certain period of time. I also tried to add both handlers to logger, but the result was doubled logging.

Do I miss something?

I also looked into source code of logging.handlers. I tried to subclass TimedRotatingFileHandler and override the method shouldRollover() to create a class with capabilities of both:

class EnhancedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler):
    def __init__(self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=0, utc=0, maxBytes=0):
        """ This is just a combination of TimedRotatingFileHandler and RotatingFileHandler (adds maxBytes to TimedRotatingFileHandler)  """
        # super(self). #It's old style class, so super doesn't work.
        logging.handlers.TimedRotatingFileHandler.__init__(self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=0, utc=0)
        self.maxBytes=maxBytes

    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.

        we are also comparing times        
        """
        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 1
        t = int(time.time())
        if t >= self.rolloverAt:
            return 1
        #print "No need to rollover: %d, %d" % (t, self.rolloverAt)
        return 0         

But like this the log creates one backup and the gets overwritten. Seems like I have to override also method doRollover() which is not so easy.

Any other idea how to create a logger which rolls the file over after certain time and also after certain size reached?


Solution

  • So I made a small hack to TimedRotatingFileHandler to be able to do rollover after both, time and size. I had to modify __init__, shouldRollover, doRollover and getFilesToDelete (see below). This is the result, when I set up when='M', interval=2, backupCount=20, maxBytes=1048576:

    -rw-r--r-- 1 user group  185164 Jun 10 00:54 sumid.log
    -rw-r--r-- 1 user group 1048462 Jun 10 00:48 sumid.log.2011-06-10_00-48.001    
    -rw-r--r-- 1 user group 1048464 Jun 10 00:48 sumid.log.2011-06-10_00-48.002    
    -rw-r--r-- 1 user group 1048533 Jun 10 00:49 sumid.log.2011-06-10_00-48.003    
    -rw-r--r-- 1 user group 1048544 Jun 10 00:50 sumid.log.2011-06-10_00-49.001    
    -rw-r--r-- 1 user group  574362 Jun 10 00:52 sumid.log.2011-06-10_00-50.001
    

    You can see that first four logs were rolled over after reaching size of 1MB, while the last rollover occurred after two minutes. So far I didn't test deleting of old log files, so it probably doesn't work. The code certainly will not work for backupCount>=1000. I append just three digits at the end of the file name.

    This is the modified code:

    class EnhancedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler):
        def __init__(self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=0, utc=0, maxBytes=0):
            """ This is just a combination of TimedRotatingFileHandler and RotatingFileHandler (adds maxBytes to TimedRotatingFileHandler)  """
            logging.handlers.TimedRotatingFileHandler.__init__(self, filename, when, interval, backupCount, encoding, delay, utc)
            self.maxBytes=maxBytes
    
        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.
    
            we are also comparing times        
            """
            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 1
            t = int(time.time())
            if t >= self.rolloverAt:
                return 1
            #print "No need to rollover: %d, %d" % (t, self.rolloverAt)
            return 0         
    
        def doRollover(self):
            """
            do a rollover; in this case, a date/time stamp is appended to the filename
            when the rollover happens.  However, you want the file to be named for the
            start of the interval, not the current time.  If there is a backup count,
            then we have to get a list of matching filenames, sort them and remove
            the one with the oldest suffix.
            """
            if self.stream:
                self.stream.close()
            # get the time that this sequence started at and make it a TimeTuple
            currentTime = int(time.time())
            dstNow = time.localtime(currentTime)[-1]
            t = self.rolloverAt - self.interval
            if self.utc:
                timeTuple = time.gmtime(t)
            else:
                timeTuple = time.localtime(t)
                dstThen = timeTuple[-1]
                if dstNow != dstThen:
                    if dstNow:
                        addend = 3600
                    else:
                        addend = -3600
                    timeTuple = time.localtime(t + addend)
            dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
            if self.backupCount > 0:
                cnt=1
                dfn2="%s.%03d"%(dfn,cnt)
                while os.path.exists(dfn2):
                    dfn2="%s.%03d"%(dfn,cnt)
                    cnt+=1                
                os.rename(self.baseFilename, dfn2)
                for s in self.getFilesToDelete():
                    os.remove(s)
            else:
                if os.path.exists(dfn):
                    os.remove(dfn)
                os.rename(self.baseFilename, dfn)
            #print "%s -> %s" % (self.baseFilename, dfn)
            self.mode = 'w'
            self.stream = self._open()
            newRolloverAt = self.computeRollover(currentTime)
            while newRolloverAt <= currentTime:
                newRolloverAt = newRolloverAt + self.interval
            #If DST changes and midnight or weekly rollover, adjust for this.
            if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
                dstAtRollover = time.localtime(newRolloverAt)[-1]
                if dstNow != dstAtRollover:
                    if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour
                        addend = -3600
                    else:           # DST bows out before next rollover, so we need to add an hour
                        addend = 3600
                    newRolloverAt += addend
            self.rolloverAt = newRolloverAt
    
        def getFilesToDelete(self):
            """
            Determine the files to delete when rolling over.
    
            More specific than the earlier method, which just used glob.glob().
            """
            dirName, baseName = os.path.split(self.baseFilename)
            fileNames = os.listdir(dirName)
            result = []
            prefix = baseName + "."
            plen = len(prefix)
            for fileName in fileNames:
                if fileName[:plen] == prefix:
                    suffix = fileName[plen:-4]
                    if self.extMatch.match(suffix):
                        result.append(os.path.join(dirName, fileName))
            result.sort()
            if len(result) < self.backupCount:
                result = []
            else:
                result = result[:len(result) - self.backupCount]
            return result