Python – Logging in Multiprocess Applications

This is not an easy question to answer succinctly.

First, the approach you choose depends on your very specific goals and constraints. To what degree will you log object messages or activities? And is logging an intrinsic activity (something that is a key, integral responsibility of the objects, or is it a secondary, really nice to have, book-keeping activity)?

There are situations where logging is intrinsic, and pervasive, but often it is a secondary concern (a book-keeping activity). This suggests that you do not want to strongly couple the logger to each object that you are tracking.

One approach to consider is something along the lines of an application global message queue, or enterprise service bus. Something that is closer to the first alternative rather than the second alternative you suggested.

Each object that you are interested in tracking with a logger would produce object or activity specific messages that each implement a common message interface that supports the common properties you are interested in each object recording in the log for identification. In each object or activity specific message, define and add the specific details to that message structure. Finally, send the message to the application's message listener queue. If acknowledgement of receipt is required, give it to the sender, so it may continue. Generally in a closed, single-host system, explicit acknowledgement of message receipt is not required.

In the application scoped message processor (globally available within your application), you would 'register' message handlers. This could be done 'lazily', as needed, or pre-emptively at start up, as part of 'bootstrapping'. Perhaps it would include a generic handler that works on any message that it receives. It may have a handler for that common logger message. It may also have a handler for several or all specific logger messages, if other activities need to occur in conjunction with that message. In any regard, the message processor would successively dequeue messages, handle messages with the registered message handlers, appropriately discard them, and then grab the next message.

Part of the implication of an application scoped message processor in a multi-threaded application is that the only guarantee to message order is that the order the message enters the message queue will play a large role in the order that it appears in a particular log.

There are strategies for making message order more deterministic, but none will be perfect in all cases. One way is to add a global message sequencer, and 'get_next' from the sequencer when crafting each and every message, then insert into an indexed queue, and wait to dequeue until the next message in the sequence arrives. This too has implications, most notably lost or discarded messages blocking the message queue.

You have made your design overly complex by creating specific logger signatures for the various latency sensitive parts.

A better design would have been to use the Logger interface from logback for all parts of the application. If performance measurements have shown that the logging causes a bottleneck for some low-latency parts, then you can offload the logging in this way:

• You create a ThreadedLogger class that implements the Logger interface and a ThreadedLogReader class.
• These two classes communicate using LogCommand objects. The LogCommand class contains all the required log information (which logger to use, the severity level and the actual log message).
• The ThreadedLogReader class runs on a separate thread and injects the log messages in the received LogCommand objects into the logback framework.

This way, your logging framework remains free from knowledge about the latency-sensitive parts of the code. If you want to make it really fancy, you could even implement a custom version of the LoggerFactory class which decides if a certain logger should be a ThreadedLogger or a regular Logger.