Analysis
Overview
At present we use log4j for logging. Although it has several logging levels that allow us to sort information according to its significance, it is difficult to use different settings for different modules/packages/classes. We'll develop our own logger which will be more flexible and will give us more control over the output information.
Characteristics of the new logger:
- logging levels (similar to those of log4j)
- filter - a list of pairs (prefix, level)
Each pair specifies the minimum logging level for a particular module/package/class...
The effective logging level for a given class is determined by the pair with the longest prefix that is a prefix of its qualified name. - targets - places to output logging information, for example a file or the console
Each target may have its own filter.
Task requirements
Functionality to be developed in this revision:
- log a message with an explicitly specified log level
- some helper methods to log a message with the appropriate log level, for example error(String msg), warn(String msg), info(String msg)
- set/change the filter
- add a target
There should be an option for the target to receive all previuos log messages that pass through its filter.
Task result
The result of this task is source code.
Implementation idea
- Unlike log4j we won't have a hierarchy of loggers, but a single static instance.
- It could keep its filter in a lexicografically sorted list and use binary search to find the effective logging level for a given class.
- When a message is logged, it should determine the caller class and its logging level and check whether the message passes through the filter or not.
- If it does it can be added to an intermediate list of log messages, from where it will be given to the targets if necessary.
- There is no need to write the message immediately after it is received.
Related
How to demo
Design
A new module will be created - org.sophie2.core.logging
Log messages will be encapsulated in LogEntry objects which will contain the message itself and some additional information about it:
- level (int)
This attributes determines the relative importance of the log message. A standard set of logging levels will be defined in the LogLevel enum - fine, trace, debug, info, warn, error and fatal (in increasing order of importance). The level of a message will be used to determine whether it should be recorded in a particular target or not. - time (long)
The system time (in milliseconds) when the message was logged. - source (StackTraceElement)
This attribute will contain information about the caller - class, method and line number that logged the message. - throwable (Throwable)
An attached Throwable object (may be null)
In order to create a new LogEntryObject, one should provide log level, message and optionally a throwable. The message can be in the form of a format string and arguments (like in java.util.Formatter). The other attributes will be determined automatically.
There will be a private static helper class StackTracer responsible for finding the source of the log message. It will find a StackTraceElement of the appropriate depth using a native method.
The LogEntry class will provide a method converting it to a formatted string. The format will be the following:
[<level>] <classname> : <message> <Throwable stacktrace>
The LogTarget interface represents an output destination for log messages, for example a console or a file. It has two methods:
- putEntry(LogEntry e) which processes log entries (or ignores them)
- close() which is responsible for freeing system resources, such as memory, output streams and open files.
It is implemented by MemLogTarget and OutputStreamTarget.
MemLogTarget is a singleton representing the main log target of SophieLog. It keeps lists of all logged messages and all targets and provides methods for adding targets and processing messages (which includes passing them to the other targets). When a new target is added, there is an option for it to receive all previously logged messages that interest it.
OutputStreamTarget class represents a target that writes messages to a stream. In order to do this asynchronously (and not block the application) it uses a BlockingQueue to store messages that should be logged and a new thread to log them. In the close() method it is important to empty the queue, flush the stream and the writer and close the stream.
A LogFilter is associated with each target to filter out irrelevant log messages and prevent them from being recorded. It contains a list of FilterEntries (defined as an inner static class). A filter entry sets a minimum logging level for all classes with fully qualified name starting with the given prefix.
The effective logging level for a given class is determined by its longest match with a prefix from the filter entries list. For instance, if the filter contains the entries ("org.sophie2", warn) and ("org.sophie2.logging", debug), the effective log level for the class org.sophie2.logging.LoggerTest is debug.
In order to make searching for the effective logging level of a class faster, the filter entries are stored in reverse lexicographical order.
SophieLog provides the main logging functionality by static methods for management of targets and for logging messages. Its state is contained in its root target - MemLogTarget which keeps track of all logged messages and attached targets.
The most important method is
log(int level, Throwable throwable, String message, Object... args)
which actually creates a new LogEntry object and passes it to the root target for further processing.
There are conveniece methods for logging a message with a particular level:
public static void tracef(String message, Object... args)
public static void tracef(Throwable t, String message, Object... args)
public static void debugf(String message, Object... args)
public static void debugf(Throwable t, String message, Object... args)
public static void infof(String message, Object... args)
public static void infof(Throwable t, String message, Object... args)
public static void warnf(String message, Object... args)
public static void warnf(Throwable t, String message, Object... args)
public static void errorf(String message, Object... args)
public static void errorf(Throwable t, String message, Object... args)
public static void fatalf(String message, Object... args)
public static void fatalf(Throwable t, String message, Object... args)
public static void trace(String message)
public static void trace(String message, Throwable t)
public static void debug(String message)
public static void debug(String message, Throwable t)
public static void info(String message)
public static void info(String message, Throwable t)
public static void warn(String message)
public static void warn(String message, Throwable t)
public static void error(String message, Object... args)
public static void error(Throwable t, String message, Object... args)
public static void fatal(String message)
public static void fatal(String message, Throwable t)
The first group of methods log a format string with arguments and the Throwable argument must be the first one in order to be separated from the message args.
The methods in the second group have the same signitures as those in log4j.
Class diagram:
ChangeSets: [3705], [3796], [3797], [3824], [3849]
Tests: LogFilterTest and SophieLogTest
To avoid cyclic dependencies, they do not extend UnitTestBase or IntegrationTestBase.
Implementation
- Since the close operation of a target may be slow (it has to print all messages that are in its queue), it may be done asynchronously, too.
- In the StreamLogTarget.close() we will set the level of the filter to NONE in order to stop new messages and insert a special log entry object in the queue as a marker that when the output queue is ready with the currently stored messages, it should quit.
- The close() method will have an argument that determines whether closing should be synchronous or not.
- The StackTracer helper class will not be inner for LogEntry any more.
- All calls to log4j loggers were replaced with calls to the new logger.
- The dependencies of all modules from log4j were removed from their pom files.
- Module classes were added in Author, Reader and Server modules. In their doStart() methods we configure the logger (i.e. add the console and a log file as targets)
- Changesets to be integrated: [3705], [3796], [3797], [3824], [3849], [3967], [4003], [4028], [4119], [4129], [4140]
Merged to the trunk [4155].
Testing
Comments
(Write comments for this or later revisions here.)
