CODEWITHSUNDEEP
python-3.xlogging
hobboy
hobboy

Reputation: 50

Python 3 logging - MemoryHandler and flushOnClose behaviour

If I forget to close the MemoryHandler before the end of the script the log message 'debug' is displayed even though flushOnClose=False (Python 3.6).

Am I doing something wrong or is this the expected behaviour? I would have thought flushOnClose would be obeyed regardless of how the handle is closed (i.e. when the script ends).

import logging.config

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# file handler, triggered by the memory handler
fh = logging.FileHandler('log.txt')
# set the logging level
fh.setLevel(logging.DEBUG)

# capacity is the number of records
mh = logging.handlers.MemoryHandler(5, flushLevel=logging.ERROR, target=fh, flushOnClose=False)

logger.addHandler(mh)

logger.debug('debug')

# mh.close()

For the arguments 5, flushLevel=logging.ERROR, target=fh, flushOnClose=False the 'debug' message should not be displaying, because

  1. I have not added 5 messages to the queue
  2. flushOnClose=False, therefore when the script ends there should not be a flush
  3. debug does not trigger flushing from flushLevel

I find that when I use mh.close() the message does not flush, as expected. However when the script ends without mh.close() (commented), the single debug message seems to get flushed despite the settings suggestion that it shouldn't.

Upvotes: 1

Views: 2213

Answers (2)

umi
umi

Reputation: 3902

Faced this issue too where logger should not supposed to print anything unless 'error' event is encountered only. Had to manually call close() on all MemoryHandlers for my Logger instance via atexit:

def _close_all_memory_handlers():
    for handler in Logger.handlers:
        if isinstance(handler, logging.handlers.MemoryHandler):
            handler.close()
import atexit
atexit.register(_close_all_memory_handlers)

This should work as long as you register this atexit handler after logging module is initialized.

Upvotes: 2

Marco smdm
Marco smdm

Reputation: 1045

I think this is the correct behaviour:

logger.debug('debug') --> this will print to your file 'debug' without waiting any flush.

Sorry...yes the default is True. I saw the add above and in my opinion the behaviour is normal, in sense that if you do NOT terminate then everything will be flush at the end of execution (this is typical in order to debug what went wrong). In case you are terminating, then the message was append to the buffer and the "False" cause the message to be destroyed within the buffer. Isn't it right behaviour?

In addition the flushOnClose does not exist in the handler class as below:

class MemoryHandler(BufferingHandler):
    """
    A handler class which buffers logging records in memory, periodically
    flushing them to a target handler. Flushing occurs whenever the buffer
    is full, or when an event of a certain severity or greater is seen.
    """
    def __init__(self, capacity, flushLevel=logging.ERROR, target=None):
        """
        Initialize the handler with the buffer size, the level at which
        flushing should occur and an optional target.

        Note that without a target being set either here or via setTarget(),
        a MemoryHandler is no use to anyone!
        """
        BufferingHandler.__init__(self, capacity)
        self.flushLevel = flushLevel
        self.target = target

    def shouldFlush(self, record):
        """
        Check for buffer full or a record at the flushLevel or higher.
        """
        return (len(self.buffer) >= self.capacity) or \
                (record.levelno >= self.flushLevel)

    def setTarget(self, target):
        """
        Set the target handler for this handler.
        """
        self.target = target

    def flush(self):
        """
        For a MemoryHandler, flushing means just sending the buffered
        records to the target, if there is one. Override if you want
        different behaviour.

        The record buffer is also cleared by this operation.
        """
        self.acquire()
        try:
            if self.target:
                for record in self.buffer:
                    self.target.handle(record)
                self.buffer = []
        finally:
            self.release()

    def close(self):
        """
        Flush, set the target to None and lose the buffer.
        """
        try:
            self.flush()
        finally:
            self.acquire()
            try:
                self.target = None
                BufferingHandler.close(self)
            finally:
                self.release()

Anyway the behavior is normal, in sense that even when you open a file, you can decide nowadays if close or not in the end. In the end the file will be closed anyway in order not to lose information :-)

Upvotes: 1

Related Questions