Building an automatic tail buffer

The log tail buffer is an extension to the logging framework. We're going to extend MemoryHandler to slightly alter its behavior. The built-in behavior for MemoryHandler includes three use cases for writing—it will write to another handler when the capacity is reached; it will write any buffered messages when logging shuts down; most importantly, it will write the entire buffer when a message of a given level is logged.

We'll change the first use case slightly. Instead of writing to the output file when the buffer is full, we'll remove the oldest messages, leaving the others in the buffer. The other two use cases for writing on exit and writing when a high-severity record is handled will be left alone. This will have the effect of dumping the last few messages before the shutdown, as well as dumping the last few messages before an error.

The default configuration for a MemoryHandler instance is to buffer messages until a message greater than or equal to the ERROR level is logged. This will lead to dumping the buffer when logging an error. It will tend to silence the business as usual messages that aren't immediate precursors of the error.

In order to understand this example, it's important to locate your Python installation and review the logging.handlers module in detail.

This extension to MemoryHandler will keep the last few messages, based on the defined capacity when the TailHandler class is created, as follows:

class TailHandler(logging.handlers.MemoryHandler):
def shouldFlush(self, record: logging.LogRecord) -> bool:
"""
Check for buffer full
or a record at the flushLevel or higher.
"""
if record.levelno >= self.flushLevel:
return True
while len(self.buffer) > self.capacity:
self.acquire()
try:
del self.buffer[0]
finally:
self.release()
return False

We extended MemoryHandler so that it will accumulate log messages up to the given capacity. When the capacity is reached, old messages will be removed as new messages are added. Note that we must lock the data structure to permit multithreaded logging.

If a message with an appropriate level is received, then the entire structure is emitted to the target handler. Usually, the target is FileHandler, which writes to a tail file for debugging and support purposes.

Additionally, when logging shuts down, the final few messages will also be written to the tail file. This should indicate a normal termination that doesn't require any debugging or support.

Generally, we'd send DEBUG level messages to this kind of handler so that we have a great deal of detail surrounding a crash situation. The configuration should specifically set the level to DEBUG rather than allowing the level to default.

Here's a configuration that uses this TailHandler:

version: 1 
disable_existing_loggers: False 
handlers: 
  console: 
    class: logging.StreamHandler 
    stream: ext://sys.stderr 
    formatter: basic 
  tail: 
    (): __main__.TailHandler 
    target: cfg://handlers.console 
    capacity: 5 
formatters: 
  basic: 
    style: "{" 
    format: "{levelname:s}:{name:s}:{message:s}" 
loggers: 
  test: 
    handlers: [tail] 
    level: DEBUG 
    propagate: False 
root: 
  handlers: [console] 
  level: INFO 

The definition of TailHandler shows us several additional features of the logging configuration. It shows us class references as well as other elements of the configuration file.

We referred to a customized class definition in the configuration. A label of () specifies that the value should be interpreted as a module and class name. In this case, it is an instance of our __main__.TailHandler class. A label of class instead of () uses a module and class that are part of the logging package.

We referred to another logger that's defined within the configuration. cfg://handlers.console refers to the console handler defined within the handlers section of this configuration file. For demonstration purposes, we used the StreamHandler tail target, which uses sys.stderr. As noted previously, a better design might be using FileHandler, which targets a debugging file.

We created the test hierarchy of loggers that used our tail handler. The messages written to these loggers will be buffered and only shown on the error or shutdown.

Here's a demonstration script:

logging.config.dictConfig(yaml.load(config8))
log = logging.getLogger("test.demo8")

log.info("Last 5 before error")
for i in range(20):
log.debug(f"Message {i:d}")
log.error("Error causes dump of last 5")

log.info("Last 5 before shutdown")
for i in range(20, 40):
log.debug(f"Message {i:d}")
log.info("Shutdown causes dump of last 5")

logging.shutdown()

We generated 20 messages prior to an error. Then, we generated 20 more messages before shutting down the logging and flushing the buffers. This will produce output like the following:

DEBUG:test.demo8:Message 15
DEBUG:test.demo8:Message 16
DEBUG:test.demo8:Message 17
DEBUG:test.demo8:Message 18
DEBUG:test.demo8:Message 19
ERROR:test.demo8:Error causes dump of last 5
DEBUG:test.demo8:Message 36
DEBUG:test.demo8:Message 37
DEBUG:test.demo8:Message 38
DEBUG:test.demo8:Message 39
INFO:test.demo8:Shutdown causes dump of last 5

The intermediate messages were silently dropped by the TailHandler object. As the capacity was set to five, the last five messages prior to an error (or shutdown) are displayed. The last five messages include four debug messages plus a final informational message.

..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset