2016年4月20日 星期三

Getting Started with SLF4J

注意事項:
    1. 文章整理至 SLF4J 官網
    2. 內容僅供參考以官方為主

Catalog

前言

從剛入職場到至今所遇到的每一個專案幾乎都會引用 log4j 這樣的套件來做日誌管理,時至數天前都始終不了解其中運作的好處及機制。近日剛好遇到日誌造成效能不佳的問題,因此抽空將 SLF4J 看了一輪,經過幾天的努力認識自己所用的日誌套件。最後,整理一些自己所看到的重要內容在此分享給各位。(log4j 與 SLF4J 同是日誌的管理套件)
首先,日誌管理是專案必需基本需求之一,其常見的應用如:
  • 專案開發過程中的追蹤
  • 紀錄伺服器發生錯誤時的內容
  • 紀錄 Monitor 統計的數據結果
  • 數據分析的依據
  • ... 
無論用途為何,日誌管理套件都應該提供詳盡且可靠的內容。
現行常見的日誌管理機制都可以找到一套 Level 規則。由於不同的套件通常規則不完全相同,在這邊簡單介紹一下 SLF4J 有 TRACE, DEBUG, INFO, WARN, ERROR 五種等級。通常我們可以通過設定當前的 Level 決定可以日誌會輸出的內容。例如:設定 ERROR 只會輸出 ERROR 而設定 WARN 則會輸出 WARN 和 ERROR... 後面依此類推。
一個比較特別的地方,SLF4J 除了是一個日誌管理套件外,它也是一個橋接管理套件,它可以將 Jakata Commons Logging(JCL), log4j 及 java.util.logging(JUL) 轉嫁至 SLF4J 上。使得管理上變得更為方便,格式及輸出都可以有更好的統一管理。
使用方面相當簡單只需要將 slf4j-api-*.jar 放入 Class Path 中就可以正常使用,橋接方式也僅需要把相對應的套件放入 Class Path 即可。例如:log4j to SLF4J 要放入 log4j-over-slf4j-*.jar 反之則放入 slf4j-log4j12-*.jar。(請注意此兩種 jar 不可同時放入,否則會發生無限迴圈,JCL 及 JUL 同理)
在使用 SLF4J 時需要小心橋接 JUL 官網有提供說明,而小編也實際測試過效能影響重大,不過好加在官網有提供簡覺得方案。第一點是記得使用 LevelChangePropagator 以及盡可能的少呼叫 JUL 系列的 Logger 這樣就可以幾乎不影響到效能。
之後的內容是小編認為比較能快速上手的一些文章剪輯,內容節錄至 SLF4J 官網。其中大致包含一個簡單的 Hello World 的日誌輸出,如何橋接 SLF4J 以及橋接時可能遇到的一些狀況。

SLF4J user manual

The Simple Logging Facade for Java (SLF4J) serves as a simple facade or abstraction for various logging frameworks, such as java.util.logging, logback and log4j. SLF4J allows the end-user to plug in the desired logging framework at deployment time. Note that SLF4J-enabling your library/application implies the addition of only a single mandatory dependency, namely slf4j-api-1.7.21.jar.
SINCE 1.6.0 If no binding is found on the class path, then SLF4J will default to a no-operation implementation.
SINCE 1.7.0 Printing methods in the Logger interface now offer variants accepting varargs instead of Object[]. This change implies that SLF4J requires JDK 1.5 or later. Under the hood the Java compiler transforms the varargs part in methods into Object[]. Thus, the Logger interface generated by the compiler is indistinguishable in 1.7.x from its 1.6.x counterpart. It follows that SLF4J version 1.7.x is totally 100% no-ifs-or-buts compatible with SLF4J version 1.6.x.
SINCE 1.7.5 Significant improvement in logger retrieval times. Given the extent of the improvement, users are highly encouraged to migrate to SLF4J 1.7.5 or later.
SINCE 1.7.9 By setting the slf4j.detectLoggerNameMismatch system property to true, SLF4J can automatically spot incorrectly named loggers.

Hello World

As customary in programming tradition, here is an example illustrating the simplest way to output "Hello world" using SLF4J. It begins by getting a logger with the name "HelloWorld". This logger is in turn used to log the message "Hello World".
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class HelloWorld {
  public static void main(String[] args) {
    Logger logger = LoggerFactory.getLogger(HelloWorld.class);
    logger.info("Hello World");
  }
}
To run this example, you first need to download the slf4j distribution, and then to unpack it. Once that is done, add the file slf4j-api-1.7.21.jar to your class path.
Compiling and running HelloWorld will result in the following output being printed on the console.
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". 
SLF4J: Defaulting to no-operation (NOP) logger implementation 
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. 
This warning is printed because no slf4j binding could be found on your class path.
The warning will disappear as soon as you add a binding to your class path. Assuming you add slf4j-simple-1.7.21.jar so that your class path contains:
  • slf4j-api-1.7.21.jar
  • slf4j-simple-1.7.21.jar
Compiling and running HelloWorld will now result in the following output on the console.
0 [main] INFO HelloWorld - Hello World

Binding with a logging framework at deployment time

As mentioned previously, SLF4J supports various logging frameworks. The SLF4J distribution ships with several jar files referred to as "SLF4J bindings", with each binding corresponding to a supported framework.

slf4j-log4j12-1.7.21.jar
Binding for log4j version 1.2, a widely used logging framework. You also need to place log4j.jar on your class path.

slf4j-jdk14-1.7.21.jar
Binding for java.util.logging, also referred to as JDK 1.4 logging

slf4j-nop-1.7.21.jar
Binding for NOP, silently discarding all logging.

slf4j-simple-1.7.21.jar
Binding for Simple implementation, which outputs all events to System.err. Only messages of level INFO and higher are printed. This binding may be useful in the context of small applications.

slf4j-jcl-1.7.21.jar
Binding for Jakarta Commons Logging. This binding will delegate all SLF4J logging to JCL.

logback-classic-1.0.13.jar (requires logback-core-1.0.13.jar)
NATIVE IMPLEMENTATION There are also SLF4J bindings external to the SLF4J project, e.g. logback which implements SLF4J natively. Logback's ch.qos.logback.classic.Logger class is a direct implementation of SLF4J's org.slf4j.Logger interface. Thus, using SLF4J in conjunction with logback involves strictly zero memory and computational overhead.
To switch logging frameworks, just replace slf4j bindings on your class path. For example, to switch from java.util.logging to log4j, just replace slf4j-jdk14-1.7.21.jar with slf4j-log4j12-1.7.21.jar.
SLF4J does not rely on any special class loader machinery. In fact, each SLF4J binding is hardwired at compile time to use one and only one specific logging framework. For example, the slf4j-log4j12-1.7.21.jar binding is bound at compile time to use log4j. In your code, in addition to slf4j-api-1.7.21.jar, you simply drop one and only one binding of your choice onto the appropriate class path location. Do not place more than one binding on your class path. Here is a graphical illustration of the general idea.
The SLF4J interfaces and their various adapters are extremely simple. Most developers familiar with the Java language should be able to read and fully understand the code in less than one hour. No knowledge of class loaders is necessary as SLF4J does not make use nor does it directly access any class loaders. As a consequence, SLF4J suffers from none of the class loader problems or memory leaks observed with Jakarta Commons Logging (JCL).
Given the simplicity of the SLF4J interfaces and its deployment model, developers of new logging frameworks should find it very easy to write SLF4J bindings.

Bridging legacy APIs

Often, some of the components you depend on rely on a logging API other than SLF4J. You may also assume that these components will not switch to SLF4J in the immediate future. To deal with such circumstances, SLF4J ships with several bridging modules which redirect calls made to log4j, JCL and java.util.logging APIs to behave as if they were made to the SLF4J API instead. The figure below illustrates the idea.
Please note that for source code under your control, you really should use the slf4j-migrator. The binary-based solutions described in this page are appropriate for software beyond your control.

Gradual migration to SLF4J from Jakarta Commons Logging (JCL)

jcl-over-slf4j.jar

To ease migration to SLF4J from JCL, SLF4J distributions include the jar file jcl-over-slf4j.jar. This jar file is intended as a drop-in replacement for JCL version 1.1.1. It implements the public API of JCL but using SLF4J underneath, hence the name "JCL over SLF4J."
Our JCL over SLF4J implementation will allow you to migrate to SLF4J gradually, especially if some of the libraries your software depends on continue to use JCL for the foreseeable future. You can immediately enjoy the benefits of SLF4J's reliability and preserve backward compatibility at the same time. Just replace commons-logging.jar with jcl-over-slf4j.jar. Subsequently, the selection of the underlying logging framework will be done by SLF4J instead of JCL but without the class loader headaches plaguing JCL. The underlying logging framework can be any of the frameworks supported by SLF4J. Often times, replacing commons-logging.jar with jcl-over-slf4j.jar will immediately and permanently solve class loader issues related to commons logging.

slf4j-jcl.jar

Some of our users after having switched to SLF4J API realize that in some contexts the use of JCL is mandatory and their use of SLF4J can be a problem. For this uncommon but important case, SLF4J offers a JCL binding, found in the file slf4j-jcl.jar. The JCL binding will delegate all logging calls made through SLF4J API to JCL. Thus, if for some reason an existing application must use JCL, your part of that application can still code against the SLF4J API in a manner transparent to the larger application environment. Your choice of SLF4J API will be invisible to the rest of the application which can continue to use JCL.

jcl-over-slf4j.jar should not be confused with slf4j-jcl.jar

JCL-over-SLF4J, i.e. jcl-over-slf4j.jar, comes in handy in situations where JCL needs to be supported for backward compatibility reasons. It can be used to fix problems associated with JCL, without necessarily adopting the SLF4J API, a decision which can be deferred to a later time.
On the other hand, slf4j-jcl.jar is useful after you have already adopted the SLF4J API for your component which needs to be embedded in a larger application environment where JCL is a formal requirement. Your software component can still use SLF4J API without disrupting the larger application. Indeed, slf4j-jcl.jar will delegate all logging decisions to JCL so that the dependency on SLF4J API by your component will be transparent to the larger whole.
Please note that jcl-over-slf4j.jar and slf4j-jcl.jar cannot be deployed at the same time. The former jar file will cause JCL to delegate the choice of the logging system to SLF4J and the latter jar file will cause SLF4J to delegate the choice of the logging system to JCL, resulting in an infinite loop.

log4j-over-slf4j

How does it work?

The log4j-over-slf4j module contains replacements of most widely used log4j classes, namely org.apache.log4j.Category, org.apache.log4j.Logger, org.apache.log4j.Priority, org.apache.log4j.Level, org.apache.log4j.MDC, and org.apache.log4j.BasicConfigurator. These replacement classes redirect all work to their corresponding SLF4J classes.
To use log4j-over-slf4j in your own application, the first step is to locate and then to replace log4j.jar with log4j-over-slf4j.jar. Note that you still need an SLF4J binding and its dependencies for log4j-over-slf4j to work properly.
In most situations, replacing a jar file is all it takes in order to migrate from log4j to SLF4J.
Note that as a result of this migration, log4j configuration files will no longer be picked up. If you need to migrate your log4j.properties file to logback, the log4j translator might be of help. For configuring logback, please refer to its manual.

When does it not work?

The log4j-over-slf4j module will not work when the application calls log4j components that are not present in the bridge. For example, when application code directly references log4j appenders, filters or the PropertyConfigurator, then log4j-over-slf4j would be an insufficient replacement for log4j. However, when log4j is configured through a configuration file, be it log4j.properties or log4j.xml, the log4j-over-slf4j module should just work fine.

What about the overhead?

There overhead of using log4j-over-slf4j instead of log4j directly is relatively small. Given that log4j-over-slf4j immediately delegates all work to SLF4J, the CPU overhead should be negligible, in the order of a few nanoseconds. There is a memory overhead corresponding to an entry in a hashmap per logger, which should be usually acceptable even for very large applications consisting of several thousand loggers. Moreover, if you choose logback as your underlying logging system, and given that logback is both much faster and more memory-efficient than log4j, the gains made by using logback should compensate for the overhead of using log4j-over-slf4j instead of log4j directly.

log4j-over-slf4j.jar and slf4j-log4j12.jar cannot be present simultaneously

The presence of slf4j-log4j12.jar, that is the log4j binding for SLF4J, will force all SLF4J calls to be delegated to log4j. The presence of log4j-over-slf4j.jar will in turn delegate all log4j API calls to their SLF4J equivalents. If both are present simultaneously, slf4j calls will be delegated to log4j, and log4j calls redirected to SLF4j, resulting in an endless loop.

jul-to-slf4j bridge

The jul-to-slf4j module includes a java.util.logging (jul) handler, namely SLF4JBridgeHandler, which routes all incoming jul records to the SLF4j API. Please see SLF4JBridgeHandler javadocs for usage instructions.
NOTE ON PERFORMANCE Contrary to other bridging modules, namely jcl-over-slf4j and log4j-over-slf4j, which reimplement JCL and respectively log4j, the jul-to-slf4j module does not reimplement the java.util.logging because packages under the java.* namespace cannot be replaced. Instead, jul-to-slf4j translates LogRecord objects into their SLF4J equivalent. Please note this translation process incurs the cost of constructing a LogRecord instance regardless of whether the SLF4J logger is disabled for the given level or nor. Consequently, j.u.l. to SLF4J translation can seriously increase the cost of disabled logging statements (60 fold or 6000%) and measurably impact the performance of enabled log statements (20% overall increase). As of logback version 0.9.25, it is possible to completely eliminate the 60 fold translation overhead for disabled log statements with the help of LevelChangePropagator.
If you are concerned about application performance, then use of SLF4JBridgeHandler is appropriate only if any one of the following two conditions is true:
  1. few j.u.l. logging statements are in play
  2. LevelChangePropagator has been installed

jul-to-slf4j.jar and slf4j-jdk14.jar cannot be present simultaneously

The presence of slf4j-jdk14.jar, that is the jul binding for SLF4J, will force SLF4J calls to be delegated to jul. On the other hand, the presence of jul-to-slf4j.jar, plus the installation of SLF4JBridgeHandler, by invoking "SLF4JBridgeHandler.install()" will route jul records to SLF4J. Thus, if both jar are present simultaneously (and SLF4JBridgeHandler is installed), slf4j calls will be delegated to jul and jul records will be routed to SLF4J, resulting in an endless loop.