[ Java 文章收集 ] Short introduction to log4j

來源自 這裡 
Preface: 
以前就有在用 Log4j, 但大多數情況是使用在 UI 應用程序, 最近要把寫好的 Web service 放上 Server, 就不能再用 System.out 這種方式來 trace 已經在線運行的服務, 因此又想起來 Log4j, 除了它可以透過 configuration 設定 Log 的 行為/Format/輸出 且它也支援 log 檔案 rotate 的功能 (設定 log 檔案到一定大小就進行 rotate, 這樣最後你會有一堆大小一致的 log, 而不是一個大到無法想想的 log 而影響到系統的運行). 下面文章是 Log4j 官網上面的教學文章, 相當實用!

Almost every large application includes its own logging or tracing API. In conformance with this rule, the E.U. SEMPER project decided to write its own tracing API. This was in early 1996. After countless enhancements, several incarnations and much work that API has evolved to become log4j, a popular logging package for Java. The package is distributed under the Apache Software License, a fully-fledged open source license certified by the open source initiative. The latest log4j version, including full-source code, class files and documentation can be found at http://logging.apache.org/log4j/. By the way, log4j has been ported to the C, C++, C#, Perl, Python, Ruby, and Eiffel languages. 

Logging does have its drawbacks. It can slow down an application. If too verbose, it can cause scrolling blindness. To alleviate these concerns, log4j is designed to be reliable, fast and extensible. Since logging is rarely the main focus of an application, the log4j API strives to be simple to understand and to use. 

Loggers, Appenders and Layouts 
Log4j has three main components: loggers, appenders and layouts. These three types of components work together to enable developers to log messages according to message type and level, and to control at runtime how these messages are formatted and where they are reported. 

Logger hierarchy 
Loggers are named entities. Logger names are case-sensitive and they follow the hierarchical naming rule: 

Named Hierarchy
A logger is said to be an ancestor of another logger if its name followed by a dot is a prefix of the descendant logger name. A logger is said to be a parent of a child logger if there are no ancestors between itself and the descendant logger.

For example, the logger named "com.foo" is a parent of the logger named "com.foo.Bar". Similarly, "java" is a parent of "java.util" and an ancestor of "java.util.Vector". This naming scheme should be familiar to most developers. 

The root logger resides at the top of the logger hierarchy. It is exceptional in two ways: 

1. it always exists,
2. it cannot be retrieved by name.

Invoking the class static Logger.getRootLogger method retrieves it. All other loggers are instantiated and retrieved with the class static Logger.getLogger method. This method takes the name of the desired logger as a parameter. 

Loggers may be assigned levels. The set of possible levels, that is: 

* TRACE,
* DEBUG,
* INFO,
* WARN,
* ERROR
* FATAL

are defined in the org.apache.log4j.Level class. Although we do not encourage you to do so, you may define your own levels by sub-classing the Level class. A perhaps better approach will be explained later on. 

If a given logger is not assigned a level, then it inherits one from its closest ancestor with an assigned level. More formally: 

Level Inheritance
The inherited level for a given logger C, is equal to the first non-null level in the logger hierarchy, starting at C and proceeding upwards in the hierarchy towards theroot logger.

To ensure that all loggers can eventually inherit a level, the root logger always has an assigned level. 

Logging requests are made by invoking one of the printing methods of a logger instance. These printing methods are debug, info, warn, error, fatal and log. By definition, the printing method determines the level of a logging request. For example, if c is a logger instance, then the statement c.info("..") is a logging request of level INFO. 

A logging request is said to be enabled if its level is higher than or equal to the level of its logger. Otherwise, the request is said to be disabled. A logger without an assigned level will inherit one from the hierarchy. For the standard levels, we have DEBUG < INFO < WARN < ERROR < FATAL. 

Here is an example of this rule. 

view plaincopy to clipboardprint?

1.  // get a logger instance named "com.foo"  
2. Logger  logger = Logger.getLogger("com.foo");  
3.   
4. // Now set its level. Normally you do not need to set the  
5. // level of a logger programmatically. This is usually done  
6. // in configuration files.  
7. logger.setLevel(Level.INFO);  
8.   
9. Logger barlogger = Logger.getLogger("com.foo.Bar");  
10.   
11. // This request is enabled, because WARN >= INFO.  
12. logger.warn("Low fuel level.");  
13.   
14. // This request is disabled, because DEBUG < INFO.  
15. logger.debug("Starting search for nearest gas station.");  
16.   
17. // The logger instance barlogger, named "com.foo.Bar",  
18. // will inherit its level from the logger named  
19. // "com.foo" Thus, the following request is enabled  
20. // because INFO >= INFO.  
21. barlogger.info("Located nearest gas station.");  
22.   
23. // This request is disabled, because DEBUG < INFO.  
24. barlogger.debug("Exiting gas station search");  

Calling the getLogger method with the same name will always return a reference to the exact same logger object. 

Log4j makes it easy to name loggers by software component. This can be accomplished by statically instantiating a logger in each class, with the logger name equal to the fully qualified name of the class. This is a useful and straightforward method of defining loggers. As the log output bears the name of the generating logger, this naming strategy makes it easy to identify the origin of a log message. However, this is only one possible, albeit common, strategy for naming loggers. Log4j does not restrict the possible set of loggers. The developer is free to name the loggers as desired. 

Appenders and Layouts 
The ability to selectively enable or disable logging requests based on their logger is only part of the picture. Log4j allows logging requests to print to multiple destinations.In log4j speak, an output destination is called an appender. Currently, appenders exist for the console, files, GUI components, remote socket servers, JMS, NT Event Loggers, and remote UNIX Syslog daemons. It is also possible to log asynchronously. 

More than one appender can be attached to a logger. 

The addAppender method adds an appender to a given logger. Each enabled logging request for a given logger will be forwarded to all the appenders in that logger as well as the appenders higher in the hierarchy. In other words, appenders are inherited additively from the logger hierarchy. For example, if a console appender is added to the root logger, then all enabled logging requests will at least print on the console. If in addition a file appender is added to a logger, say C, then enabled logging requests for C and C's children will print on a file and on the console. It is possible to override this default behavior so that appender accumulation is no longer additive by setting the additivity flag to false. 

The rules governing appender additivity are summarized below. 

Appender Additivity
The output of a log statement of logger C will go to all the appenders in C and its ancestors. This is the meaning of the term "appender additivity".

However, if an ancestor of logger C, say P, has the additivity flag set to false, then C's output will be directed to all the appenders in C and its ancestors upto and including P but not the appenders in any of the ancestors of P.

Loggers have their additivity flag set to true by default.

More often than not, users wish to customize not only the output destination but also the output format. This is accomplished by associating a layout with an appender. The layout is responsible for formatting the logging request according to the user's wishes, whereas an appender takes care of sending the formatted output to its destination. The PatternLayout, part of the standard log4j distribution, lets the user specify the output format according to conversion patterns similar to the C languageprintf function. 

For example, the PatternLayout with the conversion pattern "%r [%t] %-5p %c - %m%n" will output something akin to: 

176 [main] INFO org.foo.Bar - Located nearest gas station.

The first field is the number of milliseconds elapsed since the start of the program. The second field is the thread making the log request. The third field is the level of the log statement. The fourth field is the name of the logger associated with the log request. The text after the '-' is the message of the statement. 

Configuration 
Inserting log requests into the application code requires a fair amount of planning and effort. Observation shows that approximately 4 percent of code is dedicated to logging. Consequently, even moderately sized applications will have thousands of logging statements embedded within their code. Given their number, it becomes imperative to manage these log statements without the need to modify them manually. 

The log4j environment is fully configurable programmatically. However, it is far more flexible to configure log4j using configuration files. Currently, configuration files can be written in XML or in Java properties (key=value) format. Let us give a taste of how this is done with the help of an imaginary application MyApp that uses log4j. 

view plaincopy to clipboardprint?

1. import com.foo.Bar;  
2.   
3. // Import log4j classes.  
4. import org.apache.log4j.Logger;  
5. import org.apache.log4j.BasicConfigurator;  
6.   
7. public class MyApp {  
8.   
9.    // Define a static logger variable so that it references the  
10.    // Logger instance named "MyApp".  
11.    static Logger logger = Logger.getLogger(MyApp.class);  
12.   
13.    public static void main(String[] args) {  
14.   
15.      // Set up a simple configuration that logs on the console.  
16.      BasicConfigurator.configure();  
17.   
18.      logger.info("Entering application.");  
19.      Bar bar = new Bar();  
20.      bar.doIt();  
21.      logger.info("Exiting application.");  
22.    }  
23. }  

MyApp begins by importing log4j related classes. It then defines a static logger variable with the name MyApp which happens to be the fully qualified name of the class. MyApp uses the Bar class defined in the package com.foo. 

view plaincopy to clipboardprint?

1. package com.foo;  
2. import org.apache.log4j.Logger;  
3.   
4. public class Bar {  
5.    static Logger logger = Logger.getLogger(Bar.class);  
6.   
7.    public void doIt() {  
8.      logger.debug("Did it again!");  
9.    }  
10. }  

The invocation of the BasicConfigurator.configure method creates a rather simple log4j setup. This method is hardwired to add to the root logger a ConsoleAppender. The output will be formatted using a PatternLayout set to the pattern "%-4r [%t] %-5p %c %x - %m%n". 

Note that by default, the root logger is assigned to Level.DEBUG. The output of MyApp is: 

0 [main] INFO MyApp - Entering application.
36 [main] DEBUG com.foo.Bar - Did it again!
51 [main] INFO MyApp - Exiting application.

The figure below depicts the object diagram of MyApp after just having called the BasicConfigurator.configure method. 
 

As a side note, let me mention that in log4j child loggers link only to their existing ancestors. In particular, the logger named com.foo.Bar is linked directly to the root logger, thereby circumventing the unused com or com.foo loggers. This significantly increases performance and reduces log4j's memory footprint. The MyApp class configures log4j by invoking BasicConfigurator.configure method. Other classes only need to import the org.apache.log4j.Logger class, retrieve the loggers they wish to use, and log away. 

The previous example always outputs the same log information. Fortunately, it is easy to modify MyApp so that the log output can be controlled at run-time. Here is a slightly modified version. 

view plaincopy to clipboardprint?

1. import com.foo.Bar;  
2.   
3. import org.apache.log4j.Logger;  
4. import org.apache.log4j.PropertyConfigurator;  
5.   
6. public class MyApp {  
7.   
8.    static Logger logger = Logger.getLogger(MyApp.class.getName());  
9.   
10.    public static void main(String[] args) {  
11.   
12.   
13.      // BasicConfigurator replaced with PropertyConfigurator.  
14.      PropertyConfigurator.configure(args[0]);  
15.   
16.      logger.info("Entering application.");  
17.      Bar bar = new Bar();  
18.      bar.doIt();  
19.      logger.info("Exiting application.");  
20.    }  
21. }  

This version of MyApp instructs PropertyConfigurator to parse a configuration file and set up logging accordingly. 

Here is a sample configuration file that results in identical output as the previous BasicConfigurator based example: 

view plaincopy to clipboardprint?

1. # Set root logger level to DEBUG and its only appender to A1.  
2. log4j.rootLogger=DEBUG, A1  
3.   
4. # A1 is set to be a ConsoleAppender.  
5. log4j.appender.A1=org.apache.log4j.ConsoleAppender  
6.   
7. # A1 uses PatternLayout.  
8. log4j.appender.A1.layout=org.apache.log4j.PatternLayout  
9. log4j.appender.A1.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n  

Suppose we are no longer interested in seeing the output of any component belonging to the com.foo package. The following configuration file shows one possible way of achieving this. 

view plaincopy to clipboardprint?

1. log4j.rootLogger=DEBUG, A1  
2. log4j.appender.A1=org.apache.log4j.ConsoleAppender  
3. log4j.appender.A1.layout=org.apache.log4j.PatternLayout  
4.   
5. # Print the date in ISO 8601 format  
6. log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n  
7.   
8. # Print only messages of level WARN or above in the package com.foo.  
9. log4j.logger.com.foo=WARN  

As the logger com.foo.Bar does not have an assigned level, it inherits its level from com.foo, which was set to WARN in the configuration file. The log statement from the Bar.doIt method has the level DEBUG, lower than the logger level WARN. Consequently, doIt() method's log request is suppressed. 

Here is another configuration file that uses multiple appenders. 

view plaincopy to clipboardprint?

1. log4j.rootLogger=debug, stdout, R  
2.   
3. log4j.appender.stdout=org.apache.log4j.ConsoleAppender  
4. log4j.appender.stdout.layout=org.apache.log4j.PatternLayout  
5.   
6. # Pattern to output the caller's file name and line number.  
7. log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n  
8.   
9. log4j.appender.R=org.apache.log4j.RollingFileAppender  
10. log4j.appender.R.File=example.log  
11.   
12. log4j.appender.R.MaxFileSize=100KB  
13. # Keep one backup file  
14. log4j.appender.R.MaxBackupIndex=1  
15.   
16. log4j.appender.R.layout=org.apache.log4j.PatternLayout  
17. log4j.appender.R.layout.ConversionPattern=%p %t %c - %m%n  

Calling the enhanced MyApp with the this configuration file will output the following on the console. 

INFO [main] (MyApp2.java:12) - Entering application.
DEBUG [main] (Bar.java:8) - Doing it again!
INFO [main] (MyApp2.java:15) - Exiting application.

In addition, as the root logger has been allocated a second appender, output will also be directed to the example.log file. This file will be rolled over when it reaches 100KB. When roll-over occurs, the old version of example.log is automatically moved to example.log.1. 

Note that to obtain these different logging behaviors we did not need to recompile code. We could just as easily have logged to a UNIX Syslog daemon, redirected all com.foo output to an NT Event logger, or forwarded logging events to a remote log4j server, which would log according to local server policy, for example by forwarding the log event to a second log4j server. 

Default Initialization Procedure 
The log4j library does not make any assumptions about its environment. In particular, there are no default log4j appenders. Under certain well-defined circumstances however, the static inializer of the Logger class will attempt to automatically configure log4j. The Java language guarantees that the static initializer of a class is called once and only once during the loading of a class into memory. It is important to remember that different classloaders may load distinct copies of the same class. These copies of the same class are considered as totally unrelated by the JVM. 

The default initialization is very useful in environments where the exact entry point to the application depends on the runtime environment. For example, the same application can be used as a stand-alone application, as an applet, or as a servlet under the control of a web-server. 

The exact default initialization algorithm is defined as follows: 

1. Setting the log4j.defaultInitOverride system property to any other value then "false" will cause log4j to skip the default initialization procedure (this procedure).
2. Set the resource string variable to the value of the log4j.configuration system property. The preferred way to specify the default initialization file is through thelog4j.configuration system property. In case the system property log4j.configuration is not defined, then set the string variable resource to its default value "log4j.properties".
3. Attempt to convert the resource variable to a URL.
4. If the resource variable cannot be converted to a URL, for example due to a MalformedURLException, then search for the resource from the classpath by callingorg.apache.log4j.helpers.Loader.getResource(resource, Logger.class) which returns a URL. Note that the string "log4j.properties" constitutes a malformed URL. SeeLoader.getResource(java.lang.String) for the list of searched locations.
5. If no URL could not be found, abort default initialization. Otherwise, configure log4j from the URL.

The PropertyConfigurator will be used to parse the URL to configure log4j unless the URL ends with the ".xml" extension, in which case the DOMConfigurator will be used. You can optionaly specify a custom configurator. The value of the log4j.configuratorClass system property is taken as the fully qualified class name of your custom configurator. The custom configurator you specify must implement the Configurator interface. 

Conclusions 
Log4j is a popular logging package written in Java. One of its distinctive features is the notion of inheritance in loggers. Using a logger hierarchy it is possible to control which log statements are output at arbitrary granularity. This helps reduce the volume of logged output and minimize the cost of logging. 

One of the advantages of the log4j API is its manageability. Once the log statements have been inserted into the code, they can be controlled with configuration files. They can be selectively enabled or disabled, and sent to different and multiple output targets in user-chosen formats. The log4j package is designed so that log statements can remain in shipped code without incurring a heavy performance cost.