net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder을 이용한 JSON포맷 동적 필드 로그 생성

개요

• 로그를 JSON으로 출력하는 방법은 여러가지가 있다.
• Logback의 LoggingEventCompositeJsonEncoder을 이용해서 출력하는 경우에 대해 설명한다.
• 이름에서 알겠지만 LoggingEventCompositeJsonEncoder이기 때문에 JSON형식일 때만 가능하다.
• LoggingEventCompositeJsonEncoder을 이용하는 경우 동적 필드 설정도 가능하다.
  (다른 encoder에서도 기본 지원인지는 미확인)

---

구동 환경

pom.xml

<parent>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-parent</artifactId>
    <version>3.2.0-SNAPSHOT</version>
    <relativePath/> <!-- lookup parent from repository -->
</parent>
<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
    </dependency>
    
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-test</artifactId>
        <scope>test</scope>
    </dependency>

    <dependency>
        <groupId>net.logstash.logback</groupId>
        <artifactId>logstash-logback-encoder</artifactId>
        <version>7.4</version>
    </dependency>
</dependencies>

---

JSON패턴 설정 방법

 

패턴 태그 - 패턴 태그에 전체 JSON포맷을 설정(안 좋은 예)

• 아래는 예이다.

<appender name="STDOUT_JSON_BASIC" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
        <providers>
            <pattern>
                <pattern>
                    {
                    "level": "%level",
                    "type":"%X{type:-application}",
                    "timestamp:":"%d{yyyy-MM-dd'T'HH:mm:ss.SSSZZ}",
                    "hostname":"%X{hostname}",
                    "requestId":"%X{requestId}",
                    "message":"%msg",
                    "stackTrace":"%ex{short}"
                    }
                </pattern>
            </pattern>
        </providers>
    </encoder>
</appender>

• 간단 설명
  • %level, %d, %msg, %ex들은 기본 필드이다.
  • %X은 MDC에 저장된 키를 출력한다.
    • %X{type:-application} 여기에서 type은 키이고 application은 키가 없을 때 default값이다.
  • %ex는 exception이 발생했을 때 쓰는 필드이다.
• 이 방식의 단점:
  • 값이 없는 키도 출력되어버림.
    • stackTrace는 exception이 발생할 때만 필요하지만 언제나 출력된다.

---

프로바이더를 이용

• 아래는 예이다.

<appender name="STDOUT_JSON" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
        <providers>
            <logLevel>
                <fieldName>level</fieldName>
            </logLevel>
            <pattern>
                <pattern>
                    {"type":"%X{type:-application}"}
                </pattern>
            </pattern>
            <timestamp>
                <fieldName>timestamp</fieldName>
                <timeZone>KST</timeZone>
            </timestamp>
            <mdc>
                <includeMdcKeyName>hostname</includeMdcKeyName>
                <includeMdcKeyName>requestId</includeMdcKeyName>
            </mdc>
            <message/>
            <stackTrace>
                <fieldName>stackTrace</fieldName>
            </stackTrace>
        </providers>
    </encoder>
</appender>

• 간단 설명
  • 기본 필드는 각각의 프로바이더(태그)가 처리한다.
  • %X가 처리하던 MDC도 <mdc>가 처리한다.
  • fieldName은 logback의 기본 필드명을 쓰지 않을 때 사용한다.
    • stackTrace의 기본 키는 "stack_trace"이다.
      "stackTrace"를 설정해 로그 출력시에 "stackTrace"로 출력되도록 한다.
  • type키의 경우에는 디폴트가 있기 때문에 patern-patern에 정의하였다.
  • stackTrace도 exception이 발생하였을 때만 출력이 된다.
• 이 방식의 단점:
  • 위의 방식보단 다 좋지만 굳이 말하자면 mdc에 담긴 값을 출력할 때 <mdc>태그가 위 아래로 존재한다는 것?
    • <mdc>만 단독 사용시 MDC내의 모든값이 출력된다.
    • 하나의 값만 출력할 때는 <mdc><includeMdcKeyName>키</includeMdcKeyName></mdc>
      의 형식으로 하나 하나 지정해줘야한다.
      위의 예는 hostname과 requestId가 인접하여 문제가 없다.

---

새로운 필드를 추가할 때

• url을 추가한다고 가정하자.

 

MDC를 이용

• 프로바이더의 mdc에 url추가, 로그 전에 MDC에 url 설정이 필요하다.
• 프로바이더 설정

<appender name="STDOUT_JSON" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
        <providers>
            <logLevel>
                <fieldName>level</fieldName>
            </logLevel>
            <pattern>
                <pattern>
                    {"type":"%X{type:-application}"}
                </pattern>
            </pattern>
            <timestamp>
                <fieldName>timestamp</fieldName>
                <timeZone>KST</timeZone>
            </timestamp>
            <mdc>
                <includeMdcKeyName>hostname</includeMdcKeyName>
                <includeMdcKeyName>url</includeMdcKeyName>
                <includeMdcKeyName>requestId</includeMdcKeyName>
            </mdc>
            <message/>
            <stackTrace>
                <fieldName>stackTrace</fieldName>
            </stackTrace>
        </providers>
    </encoder>
</appender>

• 로그 코드

package com.example.springbootlogback.springbootlogback.log;


import java.util.UUID;

import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.boot.test.context.SpringBootTest;

@SpringBootTest
public class LogTest {

    @Test
    public void logTest(){
        var log = LoggerFactory.getLogger("stdout_json");

        var message = "message_content";
        MDC.put("type", "app");
        MDC.put("hostname", "localhost");
        MDC.put("requestId", UUID.randomUUID().toString());
        MDC.put("url", "http://localhost/test");
        log.info(message);
    }
}

• 출력(보기 편하게 개행함. 원래는 한 줄.):

{
"level": "INFO",
"type": "app",
"timestamp": "2023-08-14T16:10:03.5164147+09:00",
"hostname": "localhost",
"requestId": "55fc1faf-425e-4dcb-9409-c837583ea801",
"url": "http://localhost/test",
"message": "message_content"
}

 

새로운 조건의 추가

• url은 컨트롤러에서 리퀘스트 받을 때 한번만 출력하고 다른 코드에서는 출력하지 않도록 하자.

 

새로운 조건에 대한 해결 방법

• A: url이 없던 포맷으로 돌아가고, 컨트롤러에서 쓰는 새로운 포맷을 생성해서 쓰기.
  • 포맷이 바뀔 때 마다 매 번 새로 만들 것인가?
• B: 컨트롤러에서 로그 출력하고 MDC에서 url을 지움.
  • 컨트롤러에서 매번 지우는 코드가 필요.
    (AOP를 사용한다면 해결 가능하지만 AOP사용 않는다는 전제하에)

 

새로운 조건에 대한 새로운 해결 방법

• 로그 출력할 때 동적으로 처리할 수 있으면 좋을텐데...

 

arguments 프로바이더를 이용(새로운 해결 방법)

• 프로바이더 설정
  mdc에서 url삭제.
  message밑에 arguments추가.

<appender name="STDOUT_JSON" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
        <providers>
            <logLevel>
                <fieldName>level</fieldName>
            </logLevel>
            <pattern>
                <pattern>
                    {"type":"%X{type:-application}"}
                </pattern>
            </pattern>
            <timestamp>
                <fieldName>timestamp</fieldName>
                <timeZone>KST</timeZone>
            </timestamp>
            <mdc>
                <includeMdcKeyName>hostname</includeMdcKeyName>
                <includeMdcKeyName>requestId</includeMdcKeyName>
            </mdc>
            <message/>
            <arguments/>
            <stackTrace>
                <fieldName>stackTrace</fieldName>
            </stackTrace>
        </providers>
    </encoder>
</appender>

• 로그 코드

import java.util.UUID;

import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.boot.test.context.SpringBootTest;

import static net.logstash.logback.argument.StructuredArguments.v;

@SpringBootTest
public class LogTest {

    @Test
    public void logTest(){
        var log = LoggerFactory.getLogger("stdout_json");

        var message = "message_content";
        MDC.put("type", "app");
        MDC.put("hostname", "localhost");
        MDC.put("requestId", UUID.randomUUID().toString());

        log.info(message, v("url", "http://localhost/test"));
    }
}

• 출력(보기 편하게 개행함. 원래는 한 줄.):

{
	"level": "INFO",
	"type": "app",
	"timestamp": "2023-08-14T16:28:42.6758488+09:00",
	"hostname": "localhost",
	"requestId": "443aa6d3-3243-4b43-8889-55ccb8d8e24d",
	"message": "message_content",
	"url": "http://localhost/test"
}

---

arguments 프로바이더의 추가 사용법

 

includeNonStructuredArguments설정

• 아래와 같은 코드가 있을 때

log.info(message, v("url", "http://localhost/test"), v("httpMethod", "GET"), "ABCDE");

 

• includeNonStructuredArguments이 false이면(혹은 미설정. default가 false)
  "ABCDE"가 출력되지 않는다.

• 프로바이더 설정

<arguments>
    <includeNonStructuredArguments>false</includeNonStructuredArguments>
</arguments>

• 출력

{
	"level": "INFO",
	"type": "app",
	"timestamp": "2023-08-14T16:34:28.1549631+09:00",
	"hostname": "localhost",
	"requestId": "f08e174c-846f-43ce-969b-c23d66dd57b8",
	"message": "message_content",
	"url": "http://localhost/test",
	"httpMethod": "GET"
}

 

• includeNonStructuredArguments이 true이면(혹은 미설정. default가 false)
  "ABCDE"가 출력된다.

• 출력

{
	"level": "INFO",
	"type": "app",
	"timestamp": "2023-08-14T16:41:16.2710436+09:00",
	"hostname": "localhost",
	"requestId": "5e5ff2ba-7097-492b-89ac-86c9ecc008b5",
	"message": "message_content",
	"url": "http://localhost/test",
	"httpMethod": "GET",
	"arg2": "ABCDE"
}

---

fieldName설정

• 설정하면 로그가 그 fieldName 밑으로 들어간다.

• 프로바이더 설정

<arguments>
    <fieldName>arggg</fieldName>
    <includeNonStructuredArguments>true</includeNonStructuredArguments>
</arguments>

• 출력

{
	"level": "INFO",
	"type": "app",
	"timestamp": "2023-08-14T16:47:29.8674353+09:00",
	"hostname": "localhost",
	"requestId": "b84fc7c2-1be9-48fd-b0fa-29a60d7bdbf9",
	"message": "message_content",
	"arggg": {
		"url": "http://localhost/test",
		"httpMethod": "GET",
		"arg2": "ABCDE"
	}
}

---

nonStructuredArgumentsFieldPrefix설정

• 설정하면 키가 없는 argument의 기본 prefix가 "arg"에서 설정 값으로 바뀐다.

• 프로바이더 설정

<arguments>
    <includeNonStructuredArguments>true</includeNonStructuredArguments>
    <nonStructuredArgumentsFieldPrefix>param</nonStructuredArgumentsFieldPrefix>
</arguments>

• 출력

{
	"level": "INFO",
	"type": "app",
	"timestamp": "2023-08-14T16:52:55.982161+09:00",
	"hostname": "localhost",
	"requestId": "75c5a59a-9731-4a08-8327-cf7a6418afda",
	"message": "message_content",
	"url": "http://localhost/test",
	"httpMethod": "GET",
	"param2": "ABCDE"
}

---

여러 파라미터는 배열로 넘기는 것도 가능

위의 코드는

log.info(message, new Object[]{v("url", "http://localhost/test"), v("httpMethod", "GET"), "ABCDE"});

으로 실행해도 같다.

---

참고

logstash-logback-encoder 공식문서:

https://github.com/liangyanfeng/logstash-logback-encoder/blob/master/README.md#loggingevent_fields