Java Log framework: Logback detailed

Why use Logback

Remember the previous years of work, the company used the log framework is log4j, about from 16 to the present, whether I am involved in someone else already set up a project or my own led project, the log framework is basically replaced by Logback, summed up, logback some of the following advantages:

• Kernel rewrite, full testing, and minimal initialization of memory load all make logback performance and log4j many times higher
• Logback very naturally directly realized the slf4j, this is strictly not a merit, just so, understand slf4j premise will be easy to understand logback, but also easy to replace with other log framework Logback
• Logback has more than 200 pages of documents
• Logback when the configuration file has been modified to support automatic reload of the profile, the scanning process is fast and secure, and it does not need to create another scan thread
• Supports automatic removal of old log files to control the maximum number of log files that have been generated

In a word, if you need to select a log framework in your project, I would highly recommend using Logback.

Logback loading

We simply analyze the Logback loading process, and when we use Logback-classic.jar, the application starts, and the Logback is scanned in the following order:

• Find out if there is a value for Logback.configurationfile in the system configuration file systems properties
• Look for Logback.groovy under Classpath (that is, Logback supports groovy and XML two configuration methods)
• Looking for logback-test.xml under the Classpath
• Looking for logback.xml under the Classpath

Any of the above found, do not perform subsequent scans, according to the corresponding configuration for logback initialization, The specific code implements the Findurlofdefaultconfigurationfile method of the visible Ch.qos.logback.classic.util.ContextInitializer class.

When all of the above four items are not found, Logback calls the Ch.qos.logback.classic.BasicConfigurator configure method, constructs a consoleappender to output the log to the console, and the default log output format is "%D{HH: Mm:ss. SSS} [%thread]%-5level%logger{36}-%msg%n ".

Logback's configuration

Logback the focus should be Appender, Logger, Pattern, before this is a simple look at Logback's <configuration>,<configuration> only three properties:

• Scan: When scan is set to True, when the configuration file changes, it will be reloaded and the default is True
• Scanperiod: Detects if the configuration file has a modified interval, if no unit of time is given, the default is milliseconds, and the default time interval is 1 minutes when scan=true is in effect.
• Debug: When set to True, Logback internal log information will be printed, real-time view logback run information, default to False

<logger> and <root>

Start with the most basic <logger> <root> first.

<logger> is used to set the log print level for a package or a specific class, and to specify <appender>. <logger> can contain 0 or more <appender-ref> elements that identify this appender will be added to this logger. <logger> has only one name property, an optional level property, and an optional additivity property:

• Name: Used to specify a package that is constrained by this logger or a specific class
• Level: Used to set print levels, five common print levels from low to High are trace, DEBUG, INFO, WARN, ERROR, and if this level is not set, the current logger inherits the level of the ancestor
• Additivity: Whether to pass print information to superior logger, default to True

<root> is also a <logger> element, but it is the root logger, there is only one level property, because its name is root, about this place, a friend asked, Source code in the Loggercontext:

1 public Loggercontext () {2     super (); 3     This.loggercache = new concurrenthashmap<string, logger> (); 4  5     This.loggercontextremoteview = new Loggercontextvo (this), 6     this.root = new Logger (Logger.root_logger_name, NULL, this); 7     This.root.setLevel (level.debug); 8     loggercache.put (logger.root_logger_name, root); 9     Initevaluatormap ();     size = 1;11     this.frameworkpackages = new arraylist<string> (); 12}

The Logger constructor is:

Logger (String name, Logger parent, Loggercontext loggercontext) {    this.name = name;    This.parent = parent;    This.loggercontext = Loggercontext;}

See that the first parameter is the NAME of ROOT, and this logger.root_logger_name is defined as final public String root_logger_name = "root", which can be seen The name of the <root> node is "root".

Then write a code to test:

1 public class Slf4jtest {2  3     @Test 4 public     void Testslf4j () {5         Logger Logger = Loggerfactory.getlogger (Object.class); 6         logger.trace ("=====trace=====");   7         logger.debug ("=====debug=====");   8         logger.info ("=====info=====");   9         Logger.warn ("=====warn=====");  Ten         Logger.error ("=====error=====");     }12     13}

The configuration of the Logback.xml is:

1 <?xml version= "1.0" encoding= "UTF-8"?> 2 <configuration scan= "false" scanperiod= "60000" debug= "false" > 3< C0/><appender name= "STDOUT" class= "Ch.qos.logback.core.ConsoleAppender" > 4         <layout class= " Ch.qos.logback.classic.PatternLayout "> 5             <pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern> 6         </layout> 7     </appender> 8      9     <root level= "Info" >10         <appender-ref ref= "STDOUT"/>11     </root>12     Configuration>

Root sets the print level to "info" level,<appender> temporarily regardless of the console output:

2018-03-26 22:57:48.779 [main] INFO  java.lang.Object-=====info=====2018-03-26 22:57:48.782 [main] WARN  Java.lang.Object-=====warn=====2018-03-26 22:57:48.782 [main] ERROR Java.lang.Object-=====error=====

Logback.xml means that when the test method is run, the root node will pass the log level greater than or equal to info to the configured <appender> for "STDOUT", and "STDOUT" prints the information to the console.

Then understand the function of the <logger> node, logback.xml Modify, add a <logger> with only the name attribute;:

1 <?xml version= "1.0" encoding= "UTF-8"?> 2 <configuration scan= "false" scanperiod= "60000" debug= "false" > 3< C1/>4     <appender name= "STDOUT" class= "Ch.qos.logback.core.ConsoleAppender" > 5         <layout class= " Ch.qos.logback.classic.PatternLayout "> 6             <pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern> 7         </layout> 8     </appender> 9     <logger name= "java"/>11      <root level= "Debug" >13          <appender-ref ref= "STDOUT"/>14      </root>15       </configuration>

Note that this name refers to Loggerfactory.getlogger (Xxx.class), the package path of XXX, the less the package path the more the parent , we test the code inside is Object.class, that is Name= "Java" is the parent of name= "Java.lang", Root is the parent of all <logger>. Look at the output as:

2018-03-27 23:02:02.963 [main] DEBUG Java.lang.Object-=====debug=====2018-03-27 23:02:02.965 [main] INFO  Java.lang.Object-=====info=====2018-03-27 23:02:02.966 [main] WARN  java.lang.Object-=====warn=====2018-03-27 23:02:02.966 [main] ERROR Java.lang.Object-=====error=====

This result occurs because:

• The level is not configured in <logger>, that is, the parent of the level,<logger> that inherits the parent is <root>, then Level=debug
• Without configuring additivity, then Additivity=true, which represents this <logger> 's printing information to parent <root> Pass
• <appender-ref> is not configured, this <logger> does not print out any information

,<logger> printing information to <root> pass,<root> use "STDOUT" this <appender> print out all logs greater than or equal to the debug level. Extrapolate, we configure <logger> 's additivity to False, then the console should not print any logs, because the <logger> print information is not passed to the parent <root> pass-through and <logger > Not configured any <appender> you can try it yourself.

Next, we'll configure a <logger>:

1 <?xml version= "1.0" encoding= "UTF-8"?> 2 <configuration scan= "false" scanperiod= "60000" debug= "false" > 3< C0/>4     <appender name= "STDOUT" class= "Ch.qos.logback.core.ConsoleAppender" > 5         <layout class= " Ch.qos.logback.classic.PatternLayout "> 6             <pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern> 7         </layout> 8     </appender> 9     <logger name= "Java" additivity= "false"/>11     <logger name= "Java.lang" level= "warn" >12         < Appender-ref ref= STDOUT/>13 </logger>14 <root     level=     "Debug" >16         < Appender-ref ref= "STDOUT"/>17     </root>18      </configuration>

If you read the example above, then this example should be well understood:

• Loggerfactory.getlogger (Object.class), first find name= "Java.lang" This <logger>, and the log level is greater than or equal to warn use of "STDOUT" This < Appender> Print out
• Name= "Java.lang" This <logger> no configuration additivity, then additivity=true, print the message up, passed to the parent name= "Java" this <logger>
• Name= "Java" This <logger> additivity=false and is not associated with any <appender>, then Name= "Java" This <appender> will not print any information

From this analysis, the final print result is:

2018-03-27 23:12:16.147 [main] WARN  java.lang.Object-=====warn=====2018-03-27 23:12:16.150 [main] ERROR Java.lang.Object-=====error=====

Extrapolate, above the Name= "Java" This <appender> can set additivity to true to try what the results, if the analysis of the previous understanding of the friend should be very easy to think, there are two parts of the log output, Part of the log level is greater than or equal to warn, and part of the log level is greater than or equal to debug.

<appender>

Then look at <appender>,<appender> is the child node of <configuration>, which is the component responsible for writing the log. <appender> has two required attributes name and class:

• Name specifies the names of the <appender>
• The fully qualified name of the class designation <appender>

There are several kinds of <appender>, above we demonstrated consoleappender, therole of Consoleappender is to output the log to the console , the configuration example is:

1 <appender name= "STDOUT" class= "Ch.qos.logback.core.ConsoleAppender" >2     <encoder>3         < Pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern>4     </encoder>5 </appender>

Where encoder indicates that the parameter is formatted. In contrast to the previous example, we find that there is a difference between the use of the <layout> definition <pattern>, where the <encoder> definition <pattern> is used, and simply say:

• <encoder> was introduced after the 0.9.19 version, the previous version using <layout>,logback is highly recommended to use <encoder> instead of <layout>
• The most commonly used fileappender and its subclasses are expected to use <encoder> no longer use <layout>

About the format of <encoder> in the next section. Then we look at the Fileappender,the role of Fileappender is to write the log to the file , the configuration example is:

1 <appender name= "FILE" class= "Ch.qos.logback.core.FileAppender" >  2     <file>d:/123.log</file >  3     <append>true</append>  4     <encoder>  5         <pattern>%- 4relative [%thread]%-5level%logger{35}-%msg%n</pattern>  6     </encoder>  7 </appender >

Several of its nodes are:

• <file> represents the file name that is written, so that the relative directory can also be an absolute directory, and automatically created if the parent directory does not exist
• <appender> If True indicates that the log is appended to the end of the file, or false to empty the file
• <encoder> represents the output format, which is said later
• <prudent> If True indicates that the log will be written securely to the file, even if other fileappender are writing to this file, it is inefficient and defaults to False

Then take a look at Rollingfileappender,the role of Rollingfileappender is to scroll the record file, first log to the specified file, when a condition is met and then log to other files , The Rollingfileappender configuration is more flexible and therefore more used, as an example:

1 <appender name= "rolling-file-1" class= "Ch.qos.logback.core.rolling.RollingFileAppender" >   2     < Rollingpolicy class= "Ch.qos.logback.core.rolling.TimeBasedRollingPolicy" >   3         <fileNamePattern> Rolling-file-%d{yyyy-mm-dd}.log</filenamepattern>   4         <maxHistory>30</maxHistory>    5     </rollingPolicy>   6     <encoder>   7         <pattern>%-4relative [%thread]%-5level %LOGGER{35}-%msg%n</pattern>   8     </encoder>   9 </appender>

This is only the designation of the <rollingPolicy>,<rollingpolicy> function is to define the behavior of rollingfileappender when scrolling occurs, The above timebasedrollingpolicy is the most commonly used scrolling strategy, which specifies the scrolling strategy based on time, which is responsible for both scrolling and triggering scrolling, with the following nodes:

• <filenamepattern>, the necessary node, including the file name and the "%d" conversion, "%d" can contain a Java.text.SimpleDateFormat specified time format, such as%d{yyyy-mm}, if you directly use the% D then the format is YYYY-MM-DD. Rollingfileappender File child node is optional, you can specify a different location for the active and archive files by setting file
• <maxhistory>, optional node, control the maximum number of retained archive files, delete old files if they are out of quantity, assuming that the settings are rolled every month and <maxHistory> is 6, save only the last 6 months of the file

To other sizebasedtriggeringpolicy, to scroll according to the size of the file, you can check the data yourself.

Asynchronous Write Log

Logs are usually recorded as files to disk, such as using <ROLLINGFILEAPPENDER>, so that one write log will occur once disk IO, which is a loss of performance, so more, for each request must hit the log (for example, the request log, Log the request API, parameters, request time), we will take the asynchronous write log in a way that does not allow the write log disk io, blocking the thread thus causing unnecessary performance loss . (Do not underestimate this point, you can check the server performance optimization of the article, just because the log changed to asynchronous write, the entire QPS has been greatly improved).

Then we look at how to use Logback for asynchronous write log configuration:

 1 <?xml version= "1.0" encoding= "UTF-8"?> 2 <configuration scan= "false" scanperiod= "60000" debug= "false" > 3 4 <appender name= "STDOUT" class= "Ch.qos.logback.core.ConsoleAppender" > 5 <encoder> 6 & Lt;pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern> 7 </encoder> 8 </appender> 9 10 & Lt;appender name= "rolling-file-1" class= "Ch.qos.logback.core.rolling.RollingFileAppender" > <rollingpoli Cy class= "Ch.qos.logback.core.rolling.TimeBasedRollingPolicy" > <filenamepattern>d:/rolling-fil E-%d{yyyy-mm-dd}.log</filenamepattern> <maxHistory>30</maxHistory> < /rollingpolicy> <encoder>16 <pattern>%-4relative [%thread]%-5level%lo{35}-%m Sg%n</pattern> </encoder> </appender>19 <!--asynchronous output--> <appender name = "ASYNC" class= "Ch.qos.logback.classic.AsyncAppender" > <!--do not lose the log. By default, if the queue's 80% is full, tract, DEBUG, info-level logs are discarded--<discardingThreshold>0</discardingThreshold> <! --Change the depth of the default queue, which affects performance. The default value is zero---<queueSize>256</queueSize>-<!--add additional appender, You can add up to one--<appender-ref ref = "Rolling-file-1"/> </appender>29 <logger Name= "Java" additivity= "false"/>31 <logger name= "Java.lang" level= "DEBUG" >32 <appender-ref ref= "A     SYNC "/>33 </logger>34 <root level=" INFO ">36 <appender-ref ref=" STDOUT "/>37 </root>38 </configuration>

That is, we introduced a asyncappender, first talk about the principle of asyncappender, say a few parameters:

When we configure Asyncappender, a thread named "Asyncappender-worker-async" is initialized when the system starts

When the logging event enters Asyncappender, Asyncappender calls the Appender method, and then fills the event in buffer with the Appender method (the buffer used is blockingqueue, Before the implementation is Arrayblockingqueye), the capacity of the current buffer and whether the drop log feature is turned on, the asyncappender will exceed the buffer capacity when the consumption capacity is inferior to the capacity logging The level of the event is discarded as a way for the consumption speed to keep up with the buffer overflow process when the production speed is not keeping pace.

The function of the above thread is to remove the event from buffer and hand it to the corresponding appender for subsequent log push

As we can see from the above description, Asyncappender does not process the log, just buffers the log into a blockingqueue and creates a worker thread inside to get the log from the queue head, then logs the retrieved log to the additional appender. , thus achieving the effect of not blocking the main thread. So asyncappender just acts as an event forwarder and must refer to another appender to do things.

From the above principles, we can clearly understand the role of several parameters:

• Discardingthreshold, if equals 20, indicates that when 20% capacity is left, the trace, DEBUG, Info-level event will be discarded, only the event of the warn and error level is retained, in order to preserve all events, This value can be set to 0 and the default value is QUEUESIZE/5
• Queuesize better understand, blockingqueue maximum capacity, default is 256
• Includecallerdata indicates whether to extract the caller data, this value is set to True the cost is quite expensive, in order to improve performance, by default when the event is added to the Blockingqueue, the event associated caller data will not be extracted, Only the thread name, these relatively simple data
• Appender-ref indicates which specific <appender> log output is used by Asyncappender

<encoder>

The <encoder> node is responsible for two things:

• Converting log information to byte arrays
• Writes a byte array to the output stream

Currently Patternlayoutencoder is the only useful and default encoder, with a <pattern> node, as shown above, used to set the input format of the log, using the "%+ conversion" method, if you want to output "%" You must use the "\% "%" is escaped.

Some of the parameters available for <encoder> are represented in a table:

Conversion character	Role	Whether to avoid using
C{length} Lo{length} Logger{length}	The logger name of the output log, which can have an integer parameter to shorten the <logger> name, in several cases: 1, does not enter the output full <logger> name 2. Input 0 means only the string after the right-hand <logger> rightmost point number 3. Enter a different number to indicate the number of characters before the last edge point of the output point	Whether
C{length} Class{length}	Outputs the fully qualified name of the caller of the specified record request, length ibid.	Is
D{pattern} Date{pattern}	Output time format, schema syntax compatible with Java.text.SimpleDateFormat	Whether
Caller{depth}	Outputs the location information of the caller of the generated log, and the integer option indicates the depth of the output information	Whether
L	Output the request line number of the execution log	Is
M Msg Message	Output information provided by the application	Whether
M	Enter the method name of the execution log request	Is
N	Output platform-related line breaks "\ n" or "\ r \ n", that is, newline	Whether
P Le Level	Output Log Level	Whether
R Relative	The time, in milliseconds, that the output was started from the program to the creation of the log record	Whether
T Thread	Output the name of the thread that generated the log	Whether

See the last column is "Do not use", this is because this information is not directly available (such as Request line number, call Method name), Logback must have some special means to obtain this data (such as in the log printing to produce a stack of information), this operation will affect the efficiency, so unless necessary, Otherwise, it is not recommended to print this data.

Filter

Finally, I'll take a look at <filter>,<filter> is a sub-node of <appender>, which means that it is filtered at the current log level. The most basic filter has Ch.qos.logback.classic.filter.LevelFilter and Ch.qos.logback.classic.filter.ThresholdFilter, first look at Levelfilter:

1 <configuration scan= "false" scanperiod= "60000" debug= "false" > 2  3     <appender name= "STDOUT" class= " Ch.qos.logback.core.ConsoleAppender "> 4         <encoder> 5             <pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern> 6         </encoder> 7         <filter class= " Ch.qos.logback.classic.filter.LevelFilter "> 8             <level>WARN</level> 9             <onmatch>accept </onmatch>10             <onmismatch>deny</onmismatch>11         </filter>12     </appender >13     <logger name= "java" additivity= "false"/>15 <logger     name= "Java.lang" level= "DEBUG ">16         <appender-ref ref=" STDOUT "/>17 </logger>18" <root level=     "INFO" >         <appender-ref ref= "STDOUT"/>21     </root>22     </configuration>

Look at the output:

2018-03-31 22:22:58.843 [main] WARN  java.lang.Object-=====warn=====

See that although the <logger> is configured with debug, the output is only warn, because when the match to the warn level is accepted in <filter>, a deny (Deny) is made to the warn level. Of course, you can only print out warn level logs.

Look again at the Thresholdfilter, configured as:

1 <?xml version= "1.0" encoding= "UTF-8"?> 2 <configuration scan= "false" scanperiod= "60000" debug= "false" > 3< C0/>4     <appender name= "STDOUT" class= "Ch.qos.logback.core.ConsoleAppender" > 5         <encoder> 6             <pattern>%d{yyyy-mm-dd HH:mm:ss. SSS} [%thread]%-5level%logger-%msg%n</pattern> 7         </encoder> 8         <filter class= " Ch.qos.logback.classic.filter.ThresholdFilter "> 9             <level>info</level>10         </filter>     </appender>12     <logger name= "java" additivity= "false"/>14 <logger     name= " Java.lang "level=" DEBUG ">15         <appender-ref ref=" STDOUT     "/>16 </logger>17 <root level= "INFO" >19         <appender-ref ref= "STDOUT"/>20     </root>21     Configuration>

Look at the output as:

2018-03-31 22:41:32.353 [main] INFO  java.lang.Object-=====info=====2018-03-31 22:41:32.358 [main] WARN  Java.lang.Object-=====warn=====2018-03-31 22:41:32.359 [main] ERROR Java.lang.Object-=====error=====

Because Thresholdfilter's policy is to filter the log level by less than <level>, the debug level is specified, but only info and above can be printed.

original link : https://www.cnblogs.com/xrq730/p/8628945.html

Java Log framework: Logback detailed