Audit and security logs are often duplicated between two handlers: the main control handler and a file handler that is used for audit and security reviews. This means that we'll do the following things:

• Define additional loggers for audit and security
• Define multiple handlers for these loggers
• Optionally, define additional formats for the audit handler

As shown previously, we'll often create separate hierarchies of the audit and security logs. Creating separate hierarchies of loggers is considerably simpler than trying to introduce audit or security via a new logging level. Adding new levels is challenging because the messages are essentially INFO messages; they don't belong on the WARNING side of INFO because they're not errors, nor do they belong on the DEBUG side of INFO because they're not optional.

Here's an extension to the metaclass shown earlier. This new metaclass will build a class that includes an ordinary control or debugging logger as well as a special auditing logger:

from Chapter_16.ch16_ex1 import LoggedClassMeta

class AuditedClassMeta(LoggedClassMeta):

    def __new__(cls, name, bases, namespace, **kwds):
        result = LoggedClassMeta.__new__(cls, name, bases, dict(namespace))
        for item, type_ref in result.__annotations__.items():
            if issubclass(type_ref, logging.Logger):
                prefix = "" if item == "logger" else f"{item}."
                logger = logging.getLogger(
                    f"{prefix}{result.__qualname__}")
                setattr(result, item, logger)
        return result


class AuditedClass(LoggedClass, metaclass=AuditedClassMeta):
    audit: logging.Logger
    pass

The AuditedClassMeta definition extends LoggedClassMeta. The base metaclass initialized the logged attribute with a specific logger instance based on the class name. This extension does something similar. It looks for all type annotations that reference the logging.Logger type. All of these references are automatically initialized with a class-level logger with a name based on the attribute name and the qualified class name. This lets us build an audit logger or some other specialized logger with nothing more than a type annotation.

The AuditedClass definition extends the LoggedClass definition to provide a definition for a logger attribute of the class. This class adds the audit attribute to the class. Any subclass will be created with two loggers. One logger has a name simply based on the qualified name of the class. The other logger uses the qualified name, but with a prefix that puts it in the audit hierarchy. Here's how we can use this class:

class Table(AuditedClass):

    def bet(self, bet: str, amount: int) -> None:
        self.logger.info("Betting %d on %s", amount, bet)
        self.audit.info("Bet:%r, Amount:%r", bet, amount)

We created a class that will produce records on a logger with a name that has a prefix of 'audit.'. The idea is to have two separate streams of log records from the application. In the main console log, we might want to see a simplified view, like the following example records:

INFO:Table:Betting 1 on Black
INFO:audit.Table:Bet:'Black', Amount:1

In the detailed audit file, however, we want more information, as shown in the following example records:

INFO:audit.Table:2019-03-19 07:34:58:Bet:'Black', Amount:1
INFO:audit.Table:2019-03-19 07:36:06:Bet:'Black', Amount:1

There are two different handlers for the audit.Table records. Each handler has a different format. We can configure logging to handle this additional hierarchy of loggers. We'll look at the two handlers that we need, as follows:

handlers: 
  console: 
    class: logging.StreamHandler 
    stream: ext://sys.stderr 
    formatter: basic 
  audit_file: 
    class: logging.FileHandler 
    filename: data/ch16_audit.log 
    encoding: utf-8 
    formatter: detailed 

The console handler has the user-oriented log entries, which use the basic format. The audit_file handler uses a more complex formatter named detailed. Here are the two formatters referenced by these handlers:

formatters: 
  basic: 
    style: "{" 
    format: "{levelname:s}:{name:s}:{message:s}" 
  detailed: 
    style: "{" 
    format: "{levelname:s}:{name:s}:{asctime:s}:{message:s}" 
    datefmt: "%Y-%m-%d %H:%M:%S" 

The basic format shows us just three attributes of the message. The detailed format rules are somewhat complex because the date formatting is done separately from the rest of the message formatting. The datetime module uses % style formatting. We used { style formatting for the overall message. Here are the two Logger definitions:

loggers: 
  audit: 
    handlers: [console,audit_file] 
    level: INFO 
    propagate: True 
root: 
  handlers: [console] 
  level: INFO 

We defined a logger for the audit hierarchy. All the children of audit will write their messages to both console Handler and audit_file Handler. The root logger will define all the other loggers to use the console only. We'll now see two forms of the audit messages.

The duplicate handlers provide us with the audit information in the context of the main console log, plus a focused audit trail in a separate log that can be saved for later analysis.