SpringBoot log new posture, are you really using it right?

The log system is indispensable in the project. Currently, the more popular log frameworks include log4j and logback. You may not know that the author of these two frameworks is the same person. Logback is intended to be a follow-up version of the popular log4j project. Thereby recovering where log4j left off. In addition, slf4j(Simple Logging Facade for Java**)** is a log facade framework that provides commonly used interfaces in log systems, and logback and log4j implement slf4j. This article will describe how to apply logback+slf4j in spring boot to realize log recording.

Why use logback

Logback is a new generation of log framework developed by the author of the log4j framework. It is more efficient, can adapt to many operating environments, and naturally supports SLF4J The customization of Logback is more flexible, and it is also the built-in log framework of spring boot

start using

Add dependencies:

spring-boot-starter-logging is added to the maven dependency

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-logging</artifactId>
</dependency>
copy

However, in actual development, we don't need to add this dependency directly. You will find that spring-boot-starter includes spring-boot-starter-logging, which is Spring Boot's default log framework Logback+SLF4J. And spring-boot-starter-web contains spring-boot-starte, so we only need to introduce web components:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
</dependency>
copy

default allocation:

By default, Spring Boot outputs logs to the console and does not write to log files. If you want to write a log file other than console output, you need to set the logging.file or logging.path property in application.properties

Note: The two cannot be used at the same time, if used at the same time, only logging.file take effect
logging.file=file name
logging.path=log file path

logging.level.Package names=Specify the log level under the package
logging.pattern.console=log printing rules
copy
  • logging.file, setting file, can be an absolute path or a relative path. Such as: logging.file=my.log
  • logging.path, set the directory, the spring.log file will be created in this directory, and the log content will be written, such as: logging.path=/var/log

Note: The two cannot be used at the same time. If they are used at the same time, only logging.file will take effect. You can see that this method is simple to configure, but the functions that can be realized are also very limited. If you want more complex requirements, you need the following customization configured.

Detailed explanation of logback-spring.xml

Spring Boot officially recommends using a file name with -spring as your log configuration (for example, use logback-spring.xml instead of logback.xml), name the log configuration file logback-spring.xml, and put xml in Below src/main/resource.

You can also use a custom name, such as logback-config.xml, just specify it in the application.properties file using logging.config=classpath:logback-config.xml.

Before explaining log'back-spring.xml, let's first understand three words: Logger, Appenders and Layouts (logger, appender, layout): Logback is based on three main classes: Logger, Appender and Layout. These three types of components work together to enable developers to log messages based on message type and level, and to control at runtime how those messages are formatted and where they are reported. First give a basic xml configuration as follows:

<configuration>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <!-- encoders are assigned the type
         ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>

  <logger name="chapters.configuration" level="INFO"/>

  <!-- Strictly speaking, the level attribute is not necessary since -->
  <!-- the level of the root level is set to DEBUG by default.       -->
  <root level="DEBUG">          
    <appender-ref ref="STDOUT" />
  </root>  
  
</configuration>
copy

3.1: Elements

The basic structure of a logback.xml configuration file can be described as elements, containing zero or more elements, followed by zero or more elements, followed by at most one element (or none). The following diagram illustrates this basic structure:

3.2: Elements

The element only accepts a required name attribute, an optional level attribute, and an optional additivity attribute, allowing values ​​of true or false. The value of the level attribute allows a case-insensitive string value TRACE, DEBUG, INFO, WARN, ERROR, ALL or OFF. The case-insensitive value INHERITED or its synonym NULL will force the level of the logger to be inherited from a higher level in the hierarchy, and elements may contain zero or more elements; each appender referenced in this way is added to the specified In the logger, (note: the additivity attribute is described in detail below), the logger element level is inherited.

Example 1: In the example, only the root logger is assigned a level. This level value DEBUG is inherited by other loggers X, X.Y and X.Y.Z

Logger name

Assigned level

Effective level

root

DEBUG

DEBUG

X

none

DEBUG

X.Y

none

DEBUG

X.Y.Z

none

DEBUG

Example 2: All loggers have a specified level value. Level inheritance doesn't work

Logger name

Assigned level

Effective level

root

ERROR

ERROR

X

INFO

INFO

X.Y

DEBUG

DEBUG

X.Y.Z

WARN

WARN

Example 3: Logger root, X and X.Y.Z are assigned DEBUG, INFO and ERROR levels respectively. Logger X.Y inherits its level value from its parent X.

Logger name

Assigned level

Effective level

root

DEBUG

DEBUG

X

INFO

INFO

X.Y

none

INFO

X.Y.Z

ERROR

ERROR

Example 4: In Example 4, the loggers root and X are assigned DEBUG and INFO levels respectively. Loggers X.Y and X.Y.Z inherit their level value from their nearest parent X which has the specified level.

Logger name

Assigned level

Effective level

root

DEBUG

DEBUG

X

INFO

INFO

X.Y

none

INFO

X.Y.Z

none

INFO

3.3: Elements

element configures the root logger. It supports a single attribute, the level attribute. It doesn't allow any other attributes because the additivity flag doesn't apply to the root logger. Also, since the root logger has been named "ROOT", it also does not allow a name attribute. The value of the level attribute can be one of the case-insensitive strings TRACE, DEBUG, INFO, WARN, ERROR, ALL, or OFF The element can contain zero or more elements; each appender so referenced is added to the root record In the device (note: the additivity attribute is described in detail below).

3.4: Elements

The appender is configured using an element that takes two required attributes name and class. The name attribute specifies the name of the appender, while the class attribute specifies the fully qualified name of the appender class to instantiate. Elements can contain zero or one element, zero or more elements, and zero or more elements, the following diagram illustrates common structures:

Important: In logback, output destinations are called appenders, and the addAppender method adds appenders to a given logger. Each enabled logging request for a given logger will be forwarded to all appender s in that logger and higher up in the hierarchy. In other words, appender s are additively inherited from the logger hierarchy. For example, if you add a console appender to the root logger, all enabled logging requests will at least print on the console. If a file appender is additionally added to a logger (say L), logging requests enabled for L and L's children will be printed to the file and to the console. This default behavior can be overridden by setting the logger's additivity flag to false so that no appender s are added to the accumulation.

Appender is an interface, which has many sub-interfaces and implementation classes, as shown in the following figure:

The two most important Appenders are: ConsoleAppender and RollingFileAppender.

3.4.1 : ConsoleAppender

ConsoleAppender, as the name suggests, outputs logs to the console.

3.4.2: RollingFileAppender

RollingFileAppender, a subclass of FileAppender, extends FileAppender and has the function of rolling log files. For example, a RollingFileAppender could log to a file called log.txt and change its logging target to another file once a certain condition is met.

There are two important subcomponents that interact with RollingFileAppender. The first RollingFileAppender subcomponent, the RollingPolicy , is responsible for performing the operations required for rollover. The second subcomponent of RollingFileAppender, the TriggeringPolicy will determine if and when rollover occurs. So, what the RollingPolicy is responsible for and when the TriggeringPolicy is responsible for.

For any purpose, RollingFileAppender must have both RollingPolicy and TriggeringPolicy set. However, if its RollingPolicy also implements the TriggeringPolicy interface, it only needs to specify the former explicitly.

3.4.3: Rolling strategy

TimeBasedRollingPolicy: Probably the most popular rolling policy. It defines the rollover strategy based on time, such as by day or by month. TimeBasedRollingPolicy takes responsibility for rolling and triggering said rollover. In fact, TimeBasedTriggeringPolicy implements the RollingPolicy and TriggeringPolicy interfaces.

SizeAndTimeBasedRollingPolicy: Sometimes you may want to archive files by date, but at the same time limit the size of each log file, especially if post-processing tools impose size restrictions on log files. To meet this requirement, logback provides SizeAndTimeBasedRollingPolicy , which is a subclass of TimeBasedRollingPolicy that implements a rollover policy based on time and log file size.

3.5: Elements

The most important thing in the encoder is the pattern attribute, which is responsible for controlling the format of the output log. Here is an example written by myself:

<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %highlight(%-5level) --- [%15.15(%thread)] %cyan(%-40.40(%logger{40})) : %msg%n</pattern>
copy

The output format after use is shown in the figure below

Where: **%d{yyyy-MM-dd HH:mm:ss.SSS}: date**

%-5level: log level

%highlight(): color, info is blue, warn is light red, error is bold red, debug is black

%thread: the thread that prints the log

%15.15(): If the length of the recorded thread character is less than 15 (the first), it will be filled with spaces on the left; if the length of the character is greater than 15 (the second), the extra characters will be truncated from the beginning

%logger: the class name of the log output

%-40.40(): If the recorded logger character length is less than 40 (the first), it will be filled with spaces on the right, and if the character length is greater than 40 (the second), excess characters will be truncated from the beginning

%cyan: color

%msg: log output content

%n: newline character

3.6: Elements

The two most important filters in the filter are: LevelFilter, ThresholdFilter.

LevelFilter filters events based on exact level matches. If the event's level is equal to the configured level, the filter accepts or rejects the event, depending on the configuration of the onMatch and onMismatch properties. For example, the following configuration will only print INFO-level logs, and all other logs will be disabled:

<configuration>
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>INFO</level>
      <onMatch>ACCEPT</onMatch>
      <onMismatch>DENY</onMismatch>
    </filter>
    <encoder>
      <pattern>
        %-4relative [%thread] %-5level %logger{30} - %msg%n
      </pattern>
    </encoder>
  </appender>
  <root level="DEBUG">
    <appender-ref ref="CONSOLE" />
  </root>
</configuration>
copy

ThresholdFilter filters events below a specified threshold. For events at or above the threshold, the ThresholdFilter will respond to NEUTRAL when its decision() method is called. However, events whose level is lower than the threshold will be rejected. For example, the following configuration will reject all logs lower than INFO level, and only output logs of INFO level and above:

<configuration>
  <appender name="CONSOLE"
    class="ch.qos.logback.core.ConsoleAppender">
    <!-- deny all events with a level below INFO, that is TRACE and DEBUG -->
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>INFO</level>
    </filter>
    <encoder>
      <pattern>
        %-4relative [%thread] %-5level %logger{30} - %msg%n
      </pattern>
    </encoder>
  </appender>
  <root level="DEBUG">
    <appender-ref ref="CONSOLE" />
  </root>
</configuration>
copy

Four: Detailed logback-spring.xml example:

The above introduces several important elements in xml, and the xml I configured is posted below for reference (implemented a rollover strategy based on date and size, and differentiated output by INFO and ERROR logs, and standardized log output formats, etc.) :

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">

    <!-- appender yes configuration The child node of is the component responsible for writing logs. -->
    <!-- ConsoleAppender: output log to console -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- By default, each log event is immediately flushed to the underlying output stream.  This default method is more secure, because if the application is not closed properly in the appender log events are not lost.
         However, to significantly increase logging throughput, you may wish to add the immediateFlush property is set to false -->
        <!--<immediateFlush>true</immediateFlush>-->
        <encoder>
            <!-- %37():If the character is not 37 characters long,pad with spaces on the left -->
            <!-- %-37():If the character is not 37 characters long,pad with spaces on the right -->
            <!-- %15.15():If the recorded thread character length is less than 15(First)pad with spaces on the left,If the character length is greater than 15(the second),then truncate the extra characters from the beginning -->
            <!-- %-40.40():if recorded logger Character length is less than 40(First)pad with spaces on the right,If the character length is greater than 40(the second),then truncate the extra characters from the beginning -->
            <!-- %msg: Log Printing Details -->
            <!-- %n:line break -->
            <!-- %highlight():Conversion specifiers are shown in bold red with a level of ERROR events, the red is WARN,BLUE for INFO,and default colors for other levels. -->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %highlight(%-5level) --- [%15.15(%thread)] %cyan(%-40.40(%logger{40})) : %msg%n</pattern>
            <!-- The console also uses UTF-8,Do not use GBK,Otherwise, Chinese characters will be garbled -->
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <!-- info log-->
    <!-- RollingFileAppender: Roll the record file, first record the log to the specified file, and record the log to other files when a certain condition is met -->
    <!-- The following roughly means: 1.First save the log by date, the date has changed, rename the log file name of the previous day to XXX%date%index, the new log is still project_info.log -->
    <!--             2.If the date has not changed, but the file size of the current log exceeds 10 MB , split the current log and rename-->
    <appender name="info_log" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--Log file path and name-->
        <File>logs/project_info.log</File>
        <!--Whether to append to the end of the file,The default is true-->
        <append>true</append>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>DENY</onMatch><!-- if hit ERROR just ban this log -->
            <onMismatch>ACCEPT</onMismatch><!-- Use this rule if there is no hit -->
        </filter>
        <!--There are two with RollingFileAppender Important subcomponents for interactions.  First RollingFileAppender subcomponents, i.e. RollingPolicy:Responsible for performing operations required for rollover.
         RollingFileAppender The second subcomponent of the , which is TriggeringPolicy:Will determine if and when rollover occurs.  therefore, RollingPolicy responsible for what and TriggeringPolicy responsible for when.
        for any purpose, RollingFileAppender must be set at the same time RollingPolicy and TriggeringPolicy,However, if its RollingPolicy also achieved TriggeringPolicy interface, you only need to explicitly specify the former.-->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- The log file name will be based on fileNamePattern value, which changes every once in a while -->
            <!-- file name: logs/project_info.2017-12-05.0.log -->
            <!-- Notice: SizeAndTimeBasedRollingPolicy middle %i and%d Tokens are mandatory and must exist, otherwise an error will be reported -->
            <fileNamePattern>logs/project_info.%d.%i.log</fileNamePattern>
            <!-- Every time a log file is generated, the log file is kept for 30 days, ps:maxHistory The unit is based on fileNamePattern Automatically deduced by the rollover strategy in,For example, the above selected yyyy-MM-dd,then the unit is day
            If selected above yyyy-MM,then the unit is month,In addition, the above unit defaults to yyyy-MM-dd-->
            <maxHistory>30</maxHistory>
            <!-- to 10 per log file mb When splitting starts, it will be kept for up to 30 days, but the maximum is 20 GB,Delete redundant logs even if it is less than 30 days -->
            <totalSizeCap>20GB</totalSizeCap>
            <!-- maxFileSize:This is the size of the active file, the default is 10 MB,Can be changed to 5 during testing KB look at the effect -->
            <maxFileSize>10MB</maxFileSize>
        </rollingPolicy>
        <!--Encoder-->
        <encoder>
            <!-- pattern Node, used to set the input format of the log ps:No color is set in the log file,Otherwise the color part will have ESC[0:39em Waiting for garbled characters-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level --- [%15.15(%thread)] %-40.40(%logger{40}) : %msg%n</pattern>
            <!-- Logging Encoding:Set character set here - -->
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <!-- error log-->
    <!-- RollingFileAppender: Roll the record file, first record the log to the specified file, and record the log to other files when a certain condition is met -->
    <!-- The following roughly means: 1.First save the log by date, the date has changed, rename the log file name of the previous day to XXX%date%index, the new log is still project_error.log -->
    <!--             2.If the date has not changed, but the file size of the current log exceeds 10 MB , split the current log and rename-->
    <appender name="error_log" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--Log file path and name-->
        <File>logs/project_error.log</File>
        <!--Whether to append to the end of the file,The default is true-->
        <append>true</append>
        <!-- ThresholdFilter Filter events below a specified threshold.  For events at or above the threshold, ThresholdFilter will call its decision()method response NEUTRAL.  However, events with a level below the threshold will be rejected -->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level><!-- lower than ERROR level of logging ( debug,info)will be rejected, equal to or higher than ERROR The level of the corresponding NEUTRAL -->
        </filter>
        <!--There are two with RollingFileAppender Important subcomponents for interactions.  First RollingFileAppender subcomponents, i.e. RollingPolicy:Responsible for performing operations required for rollover.
        RollingFileAppender The second subcomponent of the , which is TriggeringPolicy:Will determine if and when rollover occurs.  therefore, RollingPolicy responsible for what and TriggeringPolicy responsible for when.
       for any purpose, RollingFileAppender must be set at the same time RollingPolicy and TriggeringPolicy,However, if its RollingPolicy also realized TriggeringPolicy interface, you only need to explicitly specify the former.-->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- The name of the active file will be based on the fileNamePattern value, which changes every once in a while -->
            <!-- file name: logs/project_error.2017-12-05.0.log -->
            <!-- Notice: SizeAndTimeBasedRollingPolicy middle %i and%d Tokens are mandatory and must exist, otherwise an error will be reported -->
            <fileNamePattern>logs/project_error.%d.%i.log</fileNamePattern>
            <!-- Every time a log file is generated, the log file is kept for 30 days, ps:maxHistory The unit is based on fileNamePattern Automatically deduced by the rollover strategy in,For example, the above selected yyyy-MM-dd,then the unit is day
            If selected above yyyy-MM,then the unit is month,In addition, the above unit defaults to yyyy-MM-dd-->
            <maxHistory>30</maxHistory>
            <!-- to 10 per log file mb When splitting starts, it will be kept for up to 30 days, but the maximum is 20 GB,Delete redundant logs even if it is less than 30 days -->
            <totalSizeCap>20GB</totalSizeCap>
            <!-- maxFileSize:This is the size of the active file, the default is 10 MB,Can be changed to 5 during testing KB look at the effect -->
            <maxFileSize>10MB</maxFileSize>
        </rollingPolicy>
        <!--Encoder-->
        <encoder>
            <!-- pattern Node, used to set the input format of the log ps:No color is set in the log file,Otherwise the color part will have ESC[0:39em Waiting for garbled characters-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level --- [%15.15(%thread)] %-40.40(%logger{40}) : %msg%n</pattern>
            <!-- Logging Encoding:Set character set here - -->
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <!--Every enabled logging request for a given logger will be forwarded to all appender and higher in the hierarchy appender(do not worry about it level value).
    in other words, appender is additionally inherited from the logger hierarchy.
    For example, if the console appender to the root logger, all enabled logging requests will at least print on the console.
    If you additionally add a file appender to the logger (e.g. L),then yes L and L'Logging requests enabled by the subkey will be printed to the file and to the console.
    By adding the logger's additivity The flag is set to false,This default behavior can be overridden so that the appender accumulation-->
    <!-- configuration At most one is allowed in root,other logger If no level is set then from the parent level root inherit -->
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>

    <!-- Specify the logging level of a package in the project when there is log operation behavior -->
    <!-- The levels are [from high to low]: FATAL > ERROR > WARN > INFO > DEBUG > TRACE  -->
    <logger name="com.sailing.springbootmybatis" level="INFO">
        <appender-ref ref="info_log" />
        <appender-ref ref="error_log" />
    </logger>

    <!-- use logback enter mybatis of sql log,
    Note: If you do not add additivity="false" Then this logger will forward the output to itself and to the ancestor's logger , it will appear in the log file sql Repeat printing-->
    <logger name="com.sailing.springbootmybatis.mapper" level="DEBUG" additivity="false">
        <appender-ref ref="info_log" />
        <appender-ref ref="error_log" />
    </logger>

    <!-- additivity=false Represents the behavior of prohibiting the default accumulation, that is, com.atomikos The logs in will only be recorded in the log file, and will not output any higher level appender-->
    <logger name="com.atomikos" level="INFO" additivity="false">
        <appender-ref ref="info_log" />
        <appender-ref ref="error_log" />
    </logger>

</configuration>
copy

Five: Additional content

5.1: Let’s talk about the log output code here. Generally, someone may use the following methods to output in the code:

Object entry = new SomeObject(); 
logger.debug("The entry is " + entry);
copy

5.2: There seems to be no problem with the above, but there will be the cost of constructing message parameters, that is, converting the entry into a string and adding it. And this is true regardless of whether the message is recorded, that is, even if the log level is INFO, the operations in the brackets will be executed, but the log will not be output. The following is the optimized writing method:

if(logger.isDebugEnabled()) { 
    Object entry = new SomeObject(); 
    logger.debug("The entry is " + entry);
}
copy

5.3: In the writing method of 5.2, the set log level is first judged, and if it is in debug mode, the parameters are constructed, which improves the first writing method. But there is a better way to write it, using placeholders:

Object entry = new SomeObject(); 
logger.debug("The entry is {}.", entry);
copy

Only after evaluating whether to log, and only if the decision is yes, the logger implementation will format the message and replace the "{}" pairs with the string value of the entry. In other words, this form incurs no cost of parameter construction when logging statements are disabled.

The logback author conducted a test and found that the first and third writing methods will produce exactly the same output. However, with logging statements disabled, the third variant outperforms the first variant by at least 30 times.

If there are multiple parameters, write as follows:

logger.debug("The new entry is {}. It replaces {}.", entry, oldEntry);
copy

If you need to pass three or more parameters, you can also use the Object[] variant:

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

5.4: When recording logs, we may need to record the abnormal stack information in the file. After testing, logger.error(e) will not print out the stack information. The correct way to write it is:

logger.error("program exception, details:{}", e.getLocalizedMessage() , e);
copy

Tags: Spring logging xml Logback debug

Posted by cwheel3915 on Wed, 15 Mar 2023 15:42:39 +0530