20

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?

Björn Pollex
  • 70,106
  • 28
  • 177
  • 265
sumid
  • 1,541
  • 1
  • 21
  • 33
  • Obviously, there is no straightforward answer except diving into the library code and puzzling it out. Fortunately, the standard library is generally well written and idiomatic so if you must do this you will learn. However, I would ask this of anyone coming to me with this question: why do you want the function of time or size? What are you trying to achieve? What's the use case? As `logging` is pretty comprehensive your desire can be considered "atypical" or the facility would be there. – msw May 29 '11 at 16:50
  • I would like to add a use-case, Once in my application I wanted to keep logs in day-wise structured manner. I used the logback module of java for keeping the logs clean. Strategy : Size based rotation on 100 MB & day-wise maintaining in separate directories. And the best part, it also provided archival/compression of logs. Still looking for a similar logging library in python. – Rohit Jun 12 '19 at 12:18

4 Answers4

15

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            
Cody A. Ray
  • 5,157
  • 33
  • 31
sumid
  • 1,541
  • 1
  • 21
  • 33
  • 4
    I just fixed a bug in TimedRotatingFileHandler in Python, relating to daylight saving time and the file name time suffix. You may want to consider applying the fix here, too: http://hg.python.org/cpython/rev/a5c4b8ccca8b – Vinay Sajip Mar 14 '12 at 10:17
  • Is there a working version of this somewhere? (See @JulienGreard's comment) – Cody A. Ray Jan 13 '17 at 22:31
  • @CodyA.Ray : See the answer below I just added, I believe this is what you're looking for – Julien Greard Jan 16 '17 at 11:14
  • Okay, I've fixed and tested this version. The code isn't as simple/clean as @JulienGreard's version but it works well for me. – Cody A. Ray Jan 19 '17 at 19:01
  • works fine for me too. just one change, you should sort result in reverse order in getFilesToDelete method. – surya singh Mar 23 '18 at 12:38
7

If you really need this functionality, write your own handler based on TimedRotatingFileHandler to primarily use time for rolling over, but incorporate sized-based rollover into the existing logic. You've tried this, but you need to (at a minimum) override both shouldRollover() and doRollover() methods. The first method determines when to roll over, the second does the closing of the current log file, renaming existing files and deleting obsolete files, then opening the new file.

The doRollover() logic may be a little tricky, but certainly doable.

Vinay Sajip
  • 84,585
  • 13
  • 155
  • 165
2

Here is what I use:

import logging

class  EnhancedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler, logging.handlers.RotatingFileHandler):
    '''
        cf http://stackoverflow.com/questions/29602352/how-to-mix-logging-handlers-file-timed-and-compress-log-in-the-same-config-f

         Spec:
         Log files limited in size & date. I.E. when the size or date is overtaken, there is a file rollover
     '''

    ########################################


    def __init__(self, filename, mode = 'a', maxBytes = 0, backupCount = 0, encoding = None,
             delay = 0, when = 'h', interval = 1, utc = False):

        logging.handlers.TimedRotatingFileHandler.__init__(
        self, filename, when, interval, backupCount, encoding, delay, utc)

         logging.handlers.RotatingFileHandler.__init__(self, filename, mode, maxBytes, backupCount, encoding, delay)

     ########################################

     def computeRollover(self, currentTime):
         return logging.handlers.TimedRotatingFileHandler.computeRollover(self, currentTime)

    ########################################

    def getFilesToDelete(self):
        return logging.handlers.TimedRotatingFileHandler.getFilesToDelete(self)

    ########################################

    def doRollover(self):
        return logging.handlers.TimedRotatingFileHandler.doRollover(self)

    ########################################

    def shouldRollover(self, record):
         """ Determine if rollover should occur. """
         return (logging.handlers.TimedRotatingFileHandler.shouldRollover(self, record) or logging.handlers.RotatingFileHandler.shouldRollover(self, record))
Julien Greard
  • 805
  • 1
  • 12
  • 28
  • Does this actually work for you in production? In a quick test where I log i in range(1000) maxBytes=1000, when='m', interval=1 it looks like its missing several files / chunks of log lines. – Cody A. Ray Jan 18 '17 at 17:15
  • Yes I believe it works, I just checked it out. Actually I used to have an issue similar to yours in my unit test: it was because the extension of the log file doesn't have millisec by default, when the rollover occurs, the file pattern is the same than the previous file and overides it. A workaroud would be to change the extension (see http://stackoverflow.com/questions/24649789/how-to-force-a-rotating-name-with-pythons-timedrotatingfilehandler). In practice, in my config i set the file size ~ 1Mo, and I never have more than 1Mo of log within 1 sec – Julien Greard Jan 19 '17 at 10:40
  • 1
    Ah okay, that makes sense. I just finished editing/posted an update to the answer above that works with other combinations of sizes/time-intervals too (since it manually specified the file size-based file extension too). Thanks! Go SO collaboration! :) – Cody A. Ray Jan 19 '17 at 19:03
0

I adapted Julien's code for my usage. Now it rollover after reaching certain log size or after a period of time.

class EnhancedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler, logging.handlers.RotatingFileHandler):

def __init__(self, filename, mode='a', maxBytes=0, backupCount=0, encoding=None,
             delay=0, when='h', interval=1, utc=False):
    logging.handlers.TimedRotatingFileHandler.__init__(
        self, filename=filename, when=when, interval=interval,
        backupCount=backupCount, encoding=encoding, delay=delay, utc=utc)

    logging.handlers.RotatingFileHandler.__init__(self, filename=filename, mode=mode, maxBytes=maxBytes,
                                                  backupCount=backupCount, encoding=encoding, delay=delay)

def computeRollover(self, current_time):
    return logging.handlers.TimedRotatingFileHandler.computeRollover(self, current_time)

def doRollover(self):
    # get from logging.handlers.TimedRotatingFileHandler.doRollover()
    current_time = int(time.time())
    dst_now = time.localtime(current_time)[-1]
    new_rollover_at = self.computeRollover(current_time)

    while new_rollover_at <= current_time:
        new_rollover_at = new_rollover_at + 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:
        dst_at_rollover = time.localtime(new_rollover_at)[-1]
        if dst_now != dst_at_rollover:
            if not dst_now:  # 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
            new_rollover_at += addend
    self.rolloverAt = new_rollover_at

    return logging.handlers.RotatingFileHandler.doRollover(self)

def shouldRollover(self, record):
    return logging.handlers.TimedRotatingFileHandler.shouldRollover(self, record) or logging.handlers.RotatingFileHandler.shouldRollover(self, record)