发表更新Java / Log12 分钟读完 (大约1818个字)

Log：log4j2.xml 配置示例和异步日志详解

　　Log4j2配置：log4j2.xml文件示例配置; Log4j2 官方文档

异步日志

log4j2 支持异步日志功能, 可以大幅提高日志记录的性能。AsyncAppender,Async Loggers

AsyncAppender

AsyncAppender 默认使用 java.util.concurrent.ArrayBlockingQueue jdk内部库, 这是一个阻塞队列, 容易受锁争用的影响，在多线程环境时性能会降低变差，建议使用无锁异步记录器来获得最佳性能。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">

  <Appenders>
    <File name="MyFile" fileName="logs/app.log">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
    </File>

    <Async name="Async">
      <AppenderRef ref="MyFile"/>
    </Async>
  </Appenders>

  <Loggers>
    <Root level="error">
      <AppenderRef ref="Async"/>
    </Root>
  </Loggers>
</Configuration>

Async Loggers

LMAX Disruptor技术。异步记录器在内部使用Disruptor，一个无锁的线程间通信库，而不是队列，从而产生更高的吞吐量和更低的延迟，异步记录器的延迟始终低于同步记录器甚至基于队列的 AsyncAppender。Disruptor技术支持全异步,混合异步, 性能优于AsyncAppender。

如果记录的日志来自于业务逻辑, 官方建议使用同步记录日志消息，是因为 Async Loggers 在记录日志过程中发生问题并抛出异常，存在不容易通知到应用程序的情况。

使用 Async Loggers 异步记录日志，需要添加 disruptor 依赖，Log4j-2.9及更高版本在类路径上需要 disruptor-3.3.4.jar 或更高版本。 在Log4j-2.9之前，需要disruptor-3.0.0.jar或更高版本。

默认情况下，异步记录器不会将位置传递给 I/O 线程。 如果您的某个布局或自定义过滤器需要位置信息，则需要在所有相关记录器的配置中设置includeLocation = true，包括根记录器。

  1. 全异步记录日志
    需要设置系统环境变量：Don’t forget to set system property -Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector to make all loggers asynchronous. 
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    <?xml version="1.0" encoding="UTF-8"?>
     
    <!-- Don't forget to set system property
    -Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
         to make all loggers asynchronous. -->
     
    <Configuration status="WARN">
      <Appenders>
        <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
        <RandomAccessFile name="RandomAccessFile" fileName="async.log" immediateFlush="false" append="false">
          <PatternLayout>
            <Pattern>%d %p %c{1.} [%t] %m %ex%n</Pattern>
          </PatternLayout>
        </RandomAccessFile>
      </Appenders>
      <Loggers>
        <Root level="info" includeLocation="false">
          <AppenderRef ref="RandomAccessFile"/>
        </Root>
      </Loggers>
    </Configuration>
    当使用 AsyncLoggerContextSelector 使所有记录器异步时，请确保在配置中使用普通的 <root> 和 <logger> 元素。
  2. 混合异步
    混合异步：无需设置系统环境变量 Log4jContextSelector。
    使用<asyncRoot>或 <asyncLogger> 配置元素指定需要异步的记录器。配置只能包含一个根记录器（<root>或<asyncRoot>元素），但是可以组合异步和非异步记录器。例如，包含 <asyncLogger> 元素的配置文件还可以包含同步记录器的 <root> 和 <logger> 元素。 
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    <?xml version="1.0" encoding="UTF-8"?>
     
    <!-- No need to set system property "log4j2.contextSelector" to any value
         when using <asyncLogger> or <asyncRoot>. -->
     
    <Configuration status="WARN">
      <Appenders>
        <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
        <RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log"
                  immediateFlush="false" append="false">
          <PatternLayout>
            <Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern>
          </PatternLayout>
        </RandomAccessFile>
      </Appenders>
      <Loggers>
        <!-- pattern layout actually uses location, so we need to include it -->
        <AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
          <AppenderRef ref="RandomAccessFile"/>
        </AsyncLogger>
        <Root level="info" includeLocation="true">
          <AppenderRef ref="RandomAccessFile"/>
        </Root>
      </Loggers>
    </Configuration>

同步日志

没有配置异步日志，默认就是同步日志。

log4j2.xml 配置示例

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
<?xml version="1.0" encoding="UTF-8"?>

<!-- Configuration后面的status, 这个用于设置log4j2自身内部的信息输出, 可以不设置, 当设置成trace时,
    会看到log4j2内部各种详细输出, 可以设置成OFF(关闭) 或 Error(只输出错误信息), 30s 刷新此配置。
-->
<Configuration status="INFO" monitorInterval="30">
    <Properties>
        <Property name="log.path.root">logs</Property>
        <Property name="log.file">project_name</Property>
        <Property name="log.pattern">%d %p [%C{1.}->%M:%L] [%t] %m%n</Property>
    </Properties>

    <Appenders>
        <!-- 输出控制台日志 -->
        <Console name="Console" target="SYSTEM_OUT" follow="true">
            <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout>
                <charset>UTF-8</charset>
                <!-- 输出日志格式 -->
                <pattern>${log.pattern}</pattern>
            </PatternLayout>
        </Console>

        <!-- INFO 日志 -->
        <RollingFile name="INFO-LOG" fileName="${log.path.root}/info/${log.file}.log"
                     immediateFlush="false"
                     filePattern="${log.path.root}/info/${log.file}-%d{yyyy-MM-dd}_%i.log.gz">

            <!-- 日志过滤:只记录INFO级别的信息 -->
            <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="${log.pattern}" charset="UTF-8"/>

            <!--志日文件滚动策略-->
            <Policies>
                <!-- 按日期打包:
                     interval:int类型,日志文件滚动时间间隔,默认是1,单位精度与filePattern中配置的日期格式精度一致。
                              如上d%{yyyy-MM-dd}是精确到天,默认的interval=1表示每天滚动打包;
                                 d%{yyyy-MM-dd HH:mm}精确到分钟, 设置interval=30,表示每30分钟滚动打包
                     modulate:boolean类型,默认是false,是否对滚动文件的时间进行调制。
                            若modulate=true，则滚动时间将以0点为边界进行偏移计算调制时间,
                            如现在是20分钟,interval=30,下次文件滚动时间是30分钟,再下次是60分钟。
                -->
                <TimeBasedTriggeringPolicy modulate="true" interval="1"/>
                <!-- 按日志文件大小打包,达到20M打包 -->
                <!--<SizeBasedTriggeringPolicy size="20 MB"/>-->
            </Policies>
            <!--指定打包文件个数,默认7个,超过则覆盖之前的-->
            <!--<DefaultRolloverStrategy max="20"/>-->
            <DefaultRolloverStrategy>
                <!--删除,2级目录,保留30天内的-->
                <Delete basePath="${log.path.root}" maxDepth="2">
                    <IfFileName glob="*/*.log.gz"/>
                    <IfLastModified age="P30D"/>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <!-- ERROR 日志 -->
        <RollingFile name="ERROR-LOG" fileName="${log.path.root}/error/${log.file}.log"
                     filePattern="${log.path.root}/error/${log.file}-%d{yyyy-MM-dd}_%i.log.gz">
            <!--日志过-->
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
            </Filters>
            <PatternLayout pattern="${log.pattern}" charset="UTF-8"/>
            <Policies>
                <TimeBasedTriggeringPolicy modulate="true" interval="1"/>
            </Policies>
        </RollingFile>
    </Appenders>

    <Loggers>
        <logger name="jdbc.sqlonly" level="INFO"/>
        <logger name="jdbc.sqltiming" level="OFF"/>
        <logger name="jdbc.resultsettable" level="INFO"/>
        <logger name="jdbc.resultset" level="OFF"/>
        <logger name="jdbc.connection" level="OFF"/>
        <logger name="jdbc.audit" level="OFF"/>
        <Root level="INFO">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="INFO-LOG"/>
            <AppenderRef ref="ERROR-LOG"/>
        </Root>
    </Loggers>

</Configuration>

LogId

查看日志时，有时需要查看一个线程的整个日志流来分析整个处理流程，这时可以配置 LogId 唯一标识来标记同一个请求。
Log4j2 提供了提供了个 Thread Context(线程上下文)可以对线程进行日志标记，通过该日志标记可以记录线程的处理流程。

  1. 在日志输出模式添加LogId
    1
    <Property name="log.pattern">%d %p [LogId:%X{LogId}] [%C{1.}->%M:%L] [%t] %m%n</Property>
  2. 给每个请求创建全局唯一LogId,非常方便根据LogId链跟踪整个请求的处理过程
    监听器方式，建议使用此方式 
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    26
    27
    import org.apache.logging.log4j.ThreadContext;
    import org.springframework.stereotype.Component;

    import javax.servlet.ServletRequestEvent;
    import javax.servlet.ServletRequestListener;
    import javax.servlet.annotation.WebListener;

    /**
     * @name: RequestListener
     * @desc: 给请求增加全局唯一ID给日志输出用
     **/
    @Component
    @WebListener
    public class RequestListener implements ServletRequestListener {

        @Override
        public void requestInitialized(ServletRequestEvent sre) {
            //给请求增加全局唯一ID给日志输出用
            long logId = System.currentTimeMillis();
            ThreadContext.put("LogId", String.valueOf(logId));
        }

        @Override
        public void requestDestroyed(ServletRequestEvent sre) {

        }
    }
    也可使用拦截器实现 
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    //拦截器
    @Component
    public class LogIdInterceptor implements HandlerInterceptor {

        @Override
        public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
                throws Exception {
            long logId = System.currentTimeMillis();
            ThreadContext.put("LogId",String.valueOf(logId));
            return true;
        }
    }

    //WebConfig
    @Configuration
    public class WebAppConfig implements WebMvcConfigurer {
        public void addInterceptors(InterceptorRegistry registry) {
            registry.addInterceptor(new LogIdInterceptor());
        }
    }
  3. 输出日志效果 
    1
    2
    3
    4
    2018-11-09 18:15:08,673 INFO [LogId:1541758508672] [c.s.t.c.ShiroRealm->doGetAuthenticationInfo:34] [http-nio-8080-exec-6] 开始认证用户身份 .....
    2018-11-09 18:15:08,674 INFO [LogId:1541758508672] [n.s.l.l.s.Slf4jSpyLogDelegator->sqlOccurred:228] [http-nio-8080-exec-6] SELECT count(0) FROM user WHERE username = 'user1' 

    2018-11-09 18:15:08,675 INFO [LogId:1541758508672] [n.s.l.l.s.Slf4jSpyLogDelegator->resultSetCollected:610] [http-nio-8080-exec-6]

参数说明

  • %m 输出代码中指定的消息
  • %p 输出优先级，即DEBUG，INFO，WARN，ERROR，FATAL
  • %r 输出自应用启动到输出该log信息耗费的毫秒数
  • %c 输出所属的类目，通常就是所在类的全名
  • %t 输出产生该日志事件的线程名
  • %n 输出一个回车换行符，Windows平台为“rn”，Unix平台为“n”
  • %d 输出日志时间点的日期或时间，默认格式为ISO8601，也可以在其后指定格式，比如：%d{yyyy MMM dd HH:mm:ss,SSS}，输出类似：2002年10月18日 ：10：28，921
  • %l 输出日志事件的发生位置，包括类目名、发生的线程，以及在代码中的行数
  • %x Used to output the NDC (nested diagnostic context) associated with the thread that generated the logging event
  • %X Used to output the MDC (mapped diagnostic context) associated with the thread that generated the logging event for specified key

相关参考

  1. 聊一聊log4j2配置文件log4j2.xml
  2. Log4j2 简明教程
  3. Java 小应用日志级别异常处理最佳实践
  4. 小应用日志和异常信息聚合开源方案 stackify-log-log4j2

Log：log4j2.xml 配置示例和异步日志详解

http://blog.gxitsky.com/2018/03/31/Log-log4j2-setting-sync-logger/

作者

光星

发布于

2018-03-31

更新于

2022-06-17

许可协议

#

喜欢这篇文章？打赏一下作者吧

评论

关注我
×