Java – Logging in a Latency Sensitive System

designjavalogging

Requirements:

  1. My application is latency sensitive. Millisecond level responsiveness matters. Not all the time, but when it acts, it needs to be fast.
  2. My application needs to log information about what it's done in those times.
  3. The actual writing of the logs does not need to be that fast, just the actions.
    • However, the log files need to be written at human speed, in other words, I cannot set immediateFlush to false.

So, obviously, certain kinds of logging are getting offloaded to another thread. I am using logback as a framework, but for certain sorts of log messages I still want to offload the work to another thread.

Here is how the system currently works:

  • Each part of the latency sensitive system gets a particular logger interface injected. Each of these log methods has a signature specific to the sorts of things I know the logger will need to log.
  • A SimpleLogger implementation is written for each case. This writes to the log on the same thread.
  • I have also written a ThreadedLogger which implements ALL the logging interfaces, and gets a "backing" logger implementation injected for each sort of logger.
  • Whenever a log method is called in ThreadedLogger, it wraps the request in an SomeLogObject implements LogCommand, throws the objected into a LinkedBlockingQueue, and returns. This is similar to the Go4 Command pattern
    • There is a consumption thread that blocks on BlockingQueue.take() waiting for log objects to come in. When they do, it calls LogCommand.execute(), which calls the appropriate method in the backing Logger in ThreadedLogger.
  • Currently the LogCommand implementations are very stupid. They just call the appropriate method in the proper injected logger.

I am trying to decide if I should refactor this system. Currently, if I need to create a new place to do these offloaded logs, I have to create:

  • A new interface
  • A new implementation of this interface
  • Two new DI bindings (one for the simple logger, one for the ThreadedLogger backer)
  • A new LogCommand implementation
  • A new method for creating this LogCommand object
  • Code for injecting and storing as a field the appropriate logger in ThreadedLoggger

It seems to me that it would be a lot simpler to offload the creation of the LogObject to the calling threads, but I am concerned that I'm exposing too much of the internal workings of the log system if I do that. Not that this is necessarily a problem, but it seems unclean. Another possibility would be to combine the functionality of the simple logger implementations with their respective log objects, so the objects change from being "I am an object that does logging when given log data" to "I am a log event that knows how to log myself", and these objects can be created by a log factory.

Best Answer

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.

Related Topic