使用log4j2 JsonLayout自定义JSON格式日志

Posted on In ,

需求

log4j2 在性能上提升了很多，可以减小日志输出对高并发程序的性能。
程序的日志需要输出为json格式，通过ELK 收集和存储日志，使用json格式便于Elasticsearch提取JSON字段信息，进行搜索或者通过Kinana展示

images

log4j2 JsonLayout使用

log4j2 输出json log 使用示例

maven pom 依赖：

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
<properties>
      <java.version>1.8</java.version>
      <java.compile.version>1.8</java.compile.version>
      <log4j-api.version>2.13.1</log4j-api.version>
      <jackson.version>2.10.0</jackson.version>
  </properties>
  <dependencies>
      <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-core</artifactId>
          <version>${log4j-api.version}</version>
      </dependency>
      <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-api</artifactId>
          <version>${log4j-api.version}</version>
      </dependency>
      <!-- json format -->
      <dependency>
          <groupId>com.fasterxml.jackson.core</groupId>
          <artifactId>jackson-core</artifactId>
          <version>${jackson.version}</version>
      </dependency>
      <dependency>
          <groupId>com.fasterxml.jackson.core</groupId>
          <artifactId>jackson-databind</artifactId>
          <version>${jackson.version}</version>
      </dependency>

  • Java Code 示例：
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
import java.time.LocalDateTime;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;

public class LogJsonTest {
    private static Logger log = LogManager.getLogger(LogJsonTest.class);
    public static void main(String[] args) {
        ThreadContext.put("hello","world");
        for (int i = 0; i < 2; i++) {
            log.info("current index:{},date:{}",i, LocalDateTime.now().toString());
        }
        try{
            throw  new RuntimeException("hello i am fool");
        }catch (Exception e){ log.error("error cause:",e); }
        // test json object demo
        log.info("demo str:{}",new Demo());
    }

    static class Demo{
        private List<String> arr = new ArrayList<>();
        private String he="";
        @Override
        public String toString() {
            return Arrays.toString(arr.toArray()) ;
        }
    }
}
  • log4j 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
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="OFF">
    <properties>
        <property name="logPath">logs</property>
        <property name="logLevel">info</property>
        <property name ="project" >spring-cloud-app-demo</property>
    </properties>
    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <!-- complete="true"   Complete well-formed JSON    -->
            <JsonLayout complete="false" compact="true" eventEol="true" properties="true"
                        locationInfo="true"  includeStacktrace="true"
                        stacktraceAsString="true"
                        objectMessageAsJsonObject="true">
                <KeyValuePair key="project" value="${project}"/>
            </JsonLayout>
        </Console>
    </Appenders>

    <Loggers>
    <Logger name="com.github.ordiy" level="debug" additivity="false">
        <AppenderRef ref="console"/>
    </Logger>
    <Root level="debug">
        <AppenderRef ref="console"/>
    </Root>
    </Loggers>
</Configuration>
  • json 日志输出格式
{"thread":"main","level":"ERROR","loggerName":"com.github.ordiy.LogJsonTest","message":"error cause:","thrown":{"commonElementCount":0,"localizedMessage":"hello i am fool","message":"hello i am fool","name":"java.lang.RuntimeException","extendedStackTrace":"java.lang.RuntimeException: hello i am fool\n\tat com.github.ordiy.LogJsonTest.main(LogJsonTest.java:24) [classes/:?]\n"},"endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","instant":{"epochSecond":1594867434,"nanoOfSecond":597759000},"contextMap":{"hello":"world"},"threadId":1,"threadPriority":5,"source":{"class":"com.github.ordiy.LogJsonTest","method":"main","file":"LogJsonTest.java","line":26,"classLoaderName":"app"},"project":"spring-cloud-app-demo"}
{"thread":"main","level":"INFO","loggerName":"com.github.ordiy.LogJsonTest","message":"demo str:com.github.ordiy.LogJsonTest$Demo@18cebaa5","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","instant":{"epochSecond":1594867434,"nanoOfSecond":611577000},"contextMap":{"hello":"world"},"threadId":1,"threadPriority":5,"source":{"class":"com.github.ordiy.LogJsonTest","method":"main","file":"LogJsonTest.java","line":29,"classLoaderName":"app"},"project":"spring-cloud-app-demo"}

json layout 配置说明

JsonLayout可以使用compact locationInfo 等配置输出格式和内容,配置项解说参照log4j2 json layout
常用的配置项目：

<JsonLayout complete="false" compact="true" eventEol="true" properties="true"
                       locationInfo="true"  includeStacktrace="true"
                       stacktraceAsString="true"
                       objectMessageAsJsonObject="true">

json 输出格式及备注：
images

使用log4j 输出自定义的日志格式

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
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="OFF">
    <properties>
        <property name="logPath">logs</property>
        <property name="logLevel">info</property>
        <property name ="PROJECT_NAME" >spring-cloud-app-demo</property>
    </properties>

    <Appenders>
         <!-- immediateFlush="false"  不会立即写盘 tail时可能有延时 --> 
        <RollingFile name="fileOut" filename="${logPath}/info.log" filepattern="${logPath}/%d{yyyy-MM-dd}-info.log"  immediateFlush="false" append="false">
            <!-- complete="true"   Complete well-formed JSON    -->
            <JsonLayout   complete="false" compact="true" eventEol="true"
                        properties="false" locationInfo="false"
                        includeStacktrace="true" stacktraceAsString="true"
                        objectMessageAsJsonObject="true" >
                <!--                <KeyValuePair key="StudytonightField" value="studytonightValue" />-->
                <KeyValuePair key="project" value="${PROJECT_NAME}"/>
                <KeyValuePair key="timestamp" value="${date:yyyy-MM-dd'T'HH:mm:ss.SSSZZ}" />

                <KeyValuePair key="parent" value="$${ctx:X-B3-ParentSpanId}" />
                <KeyValuePair key="span" value="$${ctx:X-B3-SpanId}" />
                <KeyValuePair key="user" value="$${ctx:X-B3-uId}" />
                <KeyValuePair key="trace" value="${ctx:X-B3-TraceId}" />
                <KeyValuePair key="index" value="${PROJECT_NAME}-${date:yyyy-MM-dd}" />
                <!-- location 记录消耗性能 -->
                <KeyValuePair key="line_number" value="" />

                <!-- docker id  docker部署使用-->
                <!--                <KeyValuePair key="containerId" value="${docker:containerId}"/>-->
                <!--                <KeyValuePair key="containerName" value="${docker:containerName}"/>-->
                <!--                <KeyValuePair key="imageName" value="${docker:imageName}"/>-->
            </JsonLayout>
            <Policies>
                <TimeBasedTriggeringPolicy modulate="true" interval="1"/>
                <SizeBasedTriggeringPolicy size="1000MB"/>
            </Policies>
            <DefaultRolloverStrategy>
                <Delete basePath="${logPath}" maxDepth="1">
                    <IfFileName glob="*info.log*" />
                    <IfLastModified age="30d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>
    </Appenders>

    <Loggers>
    <Root level="debug">
        <AppenderRef ref="fileOut"/>
    </Root>
    </Loggers>
</Configuration>
  • Java 代码示例：
private static Logger log = LogManager.getLogger(LogJsonTest.class);
    public static void main(String[] args) {
        //log4j ctx
        ThreadContext.put("X-B3-ParentSpanId","world");
        ThreadContext.put("X-B3-SpanId","world-span");
        ThreadContext.put("X-B3-uId","world-user");
        ThreadContext.put("X-B3-uId","world-user");
        ThreadContext.put("X-B3-TraceId","world-trace");

        for (int i = 0; i < 100; i++) {
            log.info("current index:{},date:{}",i, LocalDateTime.now().toString());
        }
        try{
            throw  new RuntimeException("hello i am fool");
        }catch (Exception e){ log.error("error cause:",e); }
    }
  • Json日志输出文件示例：
{"thread":"main","level":"INFO","loggerName":"com.github.ordiy.LogJsonTest","message":"demo str:[]","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","instant":{"epochSecond":1594888243,"nanoOfSecond":231053000},"threadId":1,"threadPriority":5,"project":"spring-cloud-app-demo","timestamp":"2020-07-16T16:30:42.913+0800","parent":"world","span":"world-span","user":"world-user","trace":"world-trace","index":"spring-cloud-app-demo-2020-07-16","line_number":""}

进行pretty 优化展示后的格式：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
{
   "thread":"main",
   "level":"INFO",
   "loggerName":"com.github.ordiy.LogJsonTest",
   "message":"demo str:[]",
   "endOfBatch":false,
   "loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger",
   "instant":{
      "epochSecond":1594888243,
      "nanoOfSecond":231053000
   },
   "threadId":1,
   "threadPriority":5,
   "project":"spring-cloud-app-demo",
   "timestamp":"2020-07-16T16:30:42.913+0800",
   "parent":"world",
   "span":"world-span",
   "user":"world-user",
   "trace":"world-trace",
   "index":"spring-cloud-app-demo-2020-07-16",
   "line_number":""
}

Thread Context

thread context

通过Thread Context Stack保存context信息。

ThreadContext.put("id", UUID.randomUUID().toString()); // Add the fishtag;
ThreadContext.put("ipAddress", request.getRemoteAddr());
ThreadContext.put("loginId", session.getAttribute("loginId"));
ThreadContext.put("hostName", request.getServerName());

CloseableThreadContext

CloseableThreadContext 用于代码块内部ThreadContext。

//在IO 操作使用ThreadContext标记特定的操作信息
 try(final InputStream errorStream = process.getErrorStream();
                final InputStream in = process.getInputStream();
                final OutputStream closeOnly= process.getOutputStream(); //ignore write OutputStream
                final CloseableThreadContext.Instance ctc = CloseableThreadContext.put(ctx_key,taskName) //thread context
            ) {

}catch(IOException e){

}

跨Thread的ThreadContext

Thread之间切换会导致ThreadContext信息丢失。需要进行手动处理：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
public class StreamGobbler implements Runnable{
    private final InputStream inputStream;
    private final StringBuffer buffer;
    //在创建对象时,保存当前线程的TheadContext
    final Map<String, String> values = ThreadContext.getImmutableContext();
    final List<String> messages = ThreadContext.getImmutableStack().asList();
    public StreamGobbler(InputStream inputStream, StringBuffer consumer) {
        this.inputStream = inputStream;
        this.buffer = consumer;
    }

    @Override
    public void run() {
        //
        try (InputStreamReader in = new InputStreamReader(inputStream);
             Scanner scanner = new Scanner(in);
             //新Thread 手动设置ThreadContext
             final CloseableThreadContext.Instance ctc = CloseableThreadContext.putAll(values).pushAll(messages)){
                //code....
        } catch (IOException e) {
            log.error("StreamGobbler failed.cause:",e);
        }
    }
}

需要注意的问题

参考