logback官方文檔閱讀筆記（三）

前言

logback官方文檔

本文關於官方文檔第二章：Architecture

第二章篇幅較長，分了多篇筆記，本文爲關於第二章的筆記的第二篇。第一篇請見：logback官方文檔閱讀筆記（二）

正文

---

爲日誌記錄器添加輸出器

The ability to selectively enable or disable logging requests based on their logger is only part of the picture. Logback allows logging requests to print to multiple destinations. In logback speak, an output destination is called an appender. Currently, appenders exist for the console, files, remote socket servers, to MySQL, PostgreSQL, Oracle and other databases, JMS, and remote UNIX Syslog daemons.

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_L_, then enabled logging requests for_L_and_L_'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 of a logger to false.

The rules governing appender additivity are summarized below.

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

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

Loggers have their additivity flag set to true by default.
Since the root logger stands at the top of the logger hierarchy, the additivity flag does not apply to it.

本段主要講明瞭如下幾點：
一個輸出器，即Appender類能夠用來指明一個輸出目標。
一個日誌記錄器，即Logger類能夠經過設置輸出器addAppender(...）方法來設定被容許（等級上達成條件）記錄的日誌往哪裏輸出。
不過十分扯淡的事情是，點開文檔中addApender(...）的超連接，會發現其來到的文檔所屬的類Logger是ch.qos.logback.classic.Logger，也就是說是logback基於日誌規約的實現類。而找到真正的規約的Logger即org.slf4j.Logger，裏面根本沒有addAppender(...)這種方法。那這addAppender(...)方法到底怎麼用呢，所謂爲日誌記錄器增設輸出器是一句空話麼？本章並無給出解釋。但繼續學下去，以及對有過實踐經驗的人來講，其實能夠推測，這一增設輸出器的方法，實際上是爲logback使用logback規定的配置文檔準備的，並不會顯式地被使用者直接使用。
由於日誌記錄器存在層級，低層級的日誌記錄器的日誌輸出，也會引發其父級日誌記錄器的日誌輸出請求，被容許的請求亦會調動父級日誌記錄器的輸出器向輸出目標輸出。上述行爲可經過設置addivity屬性控制。

---

簡單引入PatternLayout的概念

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 logback distribution, lets the user specify the output format according to conversion patterns similar to the C language printf function.

For example, the PatternLayout with the conversion pattern "%-4relative [%thread] %-5level %logger{32} - %msg%n" will output something akin to:

176 [main] DEBUG manual.architecture.HelloWorld2 - Hello world.

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 request. The fourth field is the name of the logger associated with the log request. The text after the '-' is the message of the request.

這段話最重要的內容就是「用戶定製輸出的格式經過關聯一個佈置器（layout）到一個輸出器上來實現」。這一內容值得細讀，它代表佈置器是與輸出器關聯而不是與日誌記錄器關聯，同時一個日誌記錄器能夠有多個輸出器。

以後舉了一個例子講了一下佈置器（layout）的輸出格式（pattern）的寫法。但很噁心的是，沒有講清楚如何爲輸出器關聯佈置器，如何爲佈置器設置模式，下一節就是另外一個話題了。

---

日誌記錄器的相似C佔位符的格式化輸出

Parameterized logging
Given that loggers in logback-classic implement the SLF4J's Logger interface, certain printing methods admit more than one parameter. These printing method variants are mainly intended to improve performance while minimizing the impact on the readability of the code.

這裏說日誌記錄器Logger的打印（輸出）方法實現了SLF4J要求的能夠接收處理多個參數的能力。這一能力能夠提升性能並儘量不破壞可讀性，怎麼回事呢，繼續往下看。

這裏也有一個很惱人的地方，所謂'certain printing methods'，在超連接過去的API文檔中搜索print，根本沒有。結合下文才能反應過來，其實在日誌系統或者說slf4j或者說logback中，所謂的print就是指info(..),debug(...)這樣的方法。

For some Logger logger, writing,

logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
incurs the cost of constructing the message parameter, that is converting both integer i and entry[i] to a String, and concatenating intermediate strings. This is regardless of whether the message will be logged or not.

One possible way to avoid the cost of parameter construction is by surrounding the log statement with a test. Here is an example.

if(logger.isDebugEnabled()) {
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}
This way you will not incur the cost of parameter construction if debugging is disabled for logger. On the other hand, if the logger is enabled for the DEBUG level, you will incur the cost of evaluating whether the logger is enabled or not, twice: once in debugEnabled and once in debug. In practice, this overhead is insignificant because evaluating a logger takes less than 1% of the time it takes to actually log a request.

Better alternative
There exists a convenient alternative based on message formats. Assuming entry is an object, you can write:

Object entry = new SomeObject();
logger.debug("The entry is {}.", entry);
Only after evaluating whether to log or not, and only if the decision is positive, will the logger implementation format the message and replace the '{}' pair with the string value of entry. In other words, this form does not incur the cost of parameter construction when the log statement is disabled.

The following two lines will yield the exact same output. However, in case of a disabled logging statement, the second variant will outperform the first variant by a factor of at least 30.

logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);
A two argument variant is also available. For example, you can write:

logger.debug("The new entry is {}. It replaces {}.", entry, oldEntry);
If three or more arguments need to be passed, an Object[] variant is also available. For example, you can write:

Object[] paramArray = {newVal, below, above};
logger.debug("Value {} was inserted between {} and {}.", paramArray);

這一段主要介紹了容許佔位符化輸出（到這裏爲止惟一）的好處——避免日誌記錄器中未入流的輸出中的字符串拼接的資源浪費。

---

logback試圖輸出一條日誌記錄的六個過程

After we have introduced the essential logback components, we are now ready to describe the steps that the logback framework takes when the user invokes a logger's printing method. Let us now analyze the steps logback takes when the user invokes the info() method of a logger named_com.wombat_.

1. Get the filter chain decision

If it exists, the TurboFilter chain is invoked. Turbo filters can set a context-wide threshold, or filter out certain events based on information such as Marker , Level, Logger, message, or the Throwable that are associated with each logging request. If the reply of the filter chain is FilterReply.DENY , then the logging request is dropped. If it is FilterReply.NEUTRAL, then we continue with the next step, i.e. step 2. In case the reply is FilterReply.ACCEPT, we skip the next and directly jump to step 3.

2. Apply the basic selection rule

At this step, logback compares the effective level of the logger with the level of the request. If the logging request is disabled according to this test, then logback will drop the request without further processing. Otherwise, it proceeds to the next step.

3. Create a LoggingEvent object

If the request survived the previous filters, logback will create a ch.qos.logback.classic.LoggingEvent object containing all the relevant parameters of the request, such as the logger of the request, the request level, the message itself, the exception that might have been passed along with the request, the current time, the current thread, various data about the class that issued the logging request and the MDC. Note that some of these fields are initialized lazily, that is only when they are actually needed. The MDC is used to decorate the logging request with additional contextual information. MDC is discussed in a subsequent chapter.

4. Invoking appenders

After the creation of a LoggingEvent object, logback will invoke the doAppend() methods of all the applicable appenders, that is, the appenders inherited from the logger context.

All appenders shipped with the logback distribution extend the AppenderBase abstract class that implements the doAppend method in a synchronized block ensuring thread-safety. The doAppend() method of AppenderBase also invokes custom filters attached to the appender, if any such filters exist. Custom filters, which can be dynamically attached to any appender, are presented in a separate chapter.

5. Formatting the output

It is responsibility of the invoked appender to format the logging event. However, some (but not all) appenders delegate the task of formatting the logging event to a layout. A layout formats the LoggingEvent instance and returns the result as a String. Note that some appenders, such as the SocketAppender, do not transform the logging event into a string but serialize it instead. Consequently, they do not have nor require a layout.

6. Sending out the LoggingEvent

After the logging event is fully formatted it is sent to its destination by each appender.

流程圖

本段條理清晰地講明瞭logback實現下，試圖輸出一條日誌記錄的六個過程。

在本段中，引入了過濾器Filter的概念，值得細讀。實際上，繼續學習或從使用經驗來看，過濾器Filter的重要程度徹底不輸於以前提到的logback實現依賴的三大主力——輸出器Appender，日誌記錄器Logger，佈置器Layout。
同時，細讀會發如今階段一和階段四均出現了過濾器Filter，目前僅能從文本中獲知，一階段的Filter篩選時權力和範圍都更大，而四階段更多的是對一個輸出挑挑揀揀篩一篩。同時帶來一些疑問：二者是否爲同一個類？第四階段中Filter的響應和第一階段中的響應如何？
另外，在第四階段中的超連接點進去，會發現是官方文檔第七篇。也就是說官方文檔第七篇主要講的是階段四的Filter而不是階段一的。

---

logback的性能

Performance
One of the often-cited arguments against logging is its computational cost. This is a legitimate concern as even moderately-sized applications can generate thousands of log requests. Much of our development effort is spent measuring and tweaking logback's performance. Independently of these efforts, the user should still be aware of the following performance issues.

1. Logging performance when logging is turned off entirely
You can turn off logging entirely by setting the level of the root logger to Level.OFF, the highest possible level. When logging is turned off entirely, the cost of a log request consists of a method invocation plus an integer comparison. On a 3.2Ghz Pentium D machine this cost is typically around 20 nanoseconds.

However, any method invocation involves the "hidden" cost of parameter construction. For example, for some logger x writing,

x.debug("Entry number: " + i + "is " + entry[i]);
incurs the cost of constructing the message parameter, i.e. converting both integer i and entry[i] to a string, and concatenating intermediate strings, regardless of whether the message will be logged or not.

The cost of parameter construction can be quite high and depends on the size of the parameters involved. To avoid the cost of parameter construction you can take advantage of SLF4J's parameterized logging:

x.debug("Entry number: {} is {}", i, entry[i]);
This variant will not incur the cost of parameter construction. Compared to the previous call to the debug() method, it will be faster by a wide margin. The message will be formatted only if the logging request is to be sent to attached appenders. Moreover, the component that formats messages is highly optimized.

Notwithstanding the above placing log statements in tight loops, i.e. very frequently invoked code, is a lose-lose proposal, likely to result in degraded performance. Logging in tight loops will slow down your application even if logging is turned off, and if logging is turned on, will generate massive (and hence useless) output.

2. The performance of deciding whether to log or not to log when logging is turned on.
In logback, there is no need to walk the logger hierarchy. A logger knows its effective level (that is, its level, once level inheritance has been taken into consideration) when it is created. Should the level of a parent logger be changed, then all child loggers are contacted to take notice of the change. Thus, before accepting or denying a request based on the effective level, the logger can make a quasi-instantaneous decision, without needing to consult its ancestors.

3. Actual logging (formatting and writing to the output device)
This is the cost of formatting the log output and sending it to its target destination. Here again, a serious effort was made to make layouts (formatters) perform as quickly as possible. The same is true for appenders. The typical cost of actually logging is about 9 to 12 microseconds when logging to a file on the local machine. It goes up to several milliseconds when logging to a database on a remote server.

Although feature-rich, one of the foremost design goals of logback was speed of execution, a requirement which is second only to reliability. Some logback components have been rewritten several times to improve performance.

本段內容其實沒有什麼意義。主要說本身logback在性能作了不少努力使其性能強勁。惟一可讓使用者動手操做的就只有接受佔位符的輸出能力，在這節以前就已經講解。