implementation("org.apache.logging.log4j:log4j-api-kotlin:1.2.0")
implementation("org.springframework.boot:spring-boot-starter-log4j2")
implementation("com.lmax:disruptor:3.4.2")

modules {
		module("org.springframework.boot:spring-boot-starter-logging") {
			replacedBy("org.springframework.boot:spring-boot-starter-log4j2", "Use Log4j2 instead of Logback")
		}
	}

implementation("org.apache.logging.log4j:log4j-api-kotlin:1.2.0")

kotlin은 log4j2를 편하게 사용하기 위한 logging facade이다.
로깅 백엔드를 위해 사용하는 라이브러리다.

*Facade Pattern은 복잡한 구조를 단순화한 인터페이스로 제공하는 것을 의미

implementation("com.lmax:disruptor:3.4.2")

log4j2.xml 안에 AsyncLogger 사용 위해 필요

implementation("org.springframework.boot:spring-boot-starter-log4j2")

modules {
		module("org.springframework.boot:spring-boot-starter-logging") {
			replacedBy("org.springframework.boot:spring-boot-starter-log4j2", "Use Log4j2 instead of Logback")
		}
	}

default로 logback이 설정되어 있으므로 logback을 log4j2로 대체시켜줘야한다.

Log4j2 xml 설정

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="info">
    <!-- 해당 설정파일에서 사용하는 프로퍼티 -->
    <Properties>
        <Property name="layoutPattern">%style{%d{yyyy/MM/dd HH:mm:ss,SSS}}{cyan} %highlight{[%-5p]}{FATAL=bg_red, ERROR=red,INFO=green, DEBUG=blue} [%thread] (%logger{36}) - {%mdc} %msg%n</Property>
    </Properties>
    <!-- LogEvent를 전달해주는 Appender -->
    <Appenders>
        <Console name="consoleAppender" target="SYSTEM_OUT">
            <PatternLayout pattern="${layoutPattern}" />
        </Console>
    </Appenders>

    <!-- Logger-->
    <Loggers>
<!-- 기본 레벨은 info 하지만 더 자세한 정보를 원한다면 debug로 바꾸어 확인할 수 있다 -->
        <Root level="info" additivity="false" >
            <AppenderRef ref="consoleAppender"/>
        </Root>        
        <AsyncLogger name="com.example.home" level="info" additivity="false" includeLocation="true">
            <AppenderRef ref="consoleAppender"/>
        </AsyncLogger>
    </Loggers>
</Configuration>

Properties

해당 xml 파일 내부에서 사용할 변수 설정

Appenders

로그가 출력되는 위치 설정

Loggers

로깅 설정을 디테일하게 할 수 있다.
Appender를 추가하여 Console, File 등에 로그를 어디에서 출력할지 결정할 수 있다.

AsyncLogger

[1] includeLocation=”true” 옵션

asynchronous loggers need to make this decision before passing the log message to another thread; the location information will be lost after that point
다른 쓰레드로 log message가 넘어가는 과정에서 location information을 잃어버린다. 그래서 해당 설정을 true로 해주면 location까지 잘 전달 된다. (물론 해당 설정을 해주면 속도가 좀 더 느려진다.)

Async Thread 설정

import org.slf4j.MDC
import org.springframework.core.task.TaskDecorator

class LoggingTaskDecorator : TaskDecorator {

    override fun decorate(runnable: Runnable): Runnable {
        // Right now: Web thread context !
        // (Grab the current thread MDC data)
        val contextMap = MDC.getCopyOfContextMap()
        return Runnable {
            // Right now: @Async thread context !
            // (Restore the Web thread context's MDC data)
            try {
                MDC.setContextMap(contextMap)
                runnable.run()
            } finally {
                MDC.clear()
            }
        }
    }
}

MDCAdapter를 사용하게 되면 Thread에 대한 정보를 ThreadLocal에 저장하게 된다. 그럼 해당 작업이 끝날 때까지 모든 상황에서 context를 유지하고 저장하고 찾아볼 수 있다.
TaskExecutor를 비동기 처리를 위해 사용한다면 해당 executor에서 새로운 thread를 생성한다. 그런데 이 thread에서 기존 쓰레드의 context가 넘어가지 않는 문제가 있어서 기존 thread에 있는 logging 정보가 없는 thread를 생성한다.
그래서 TaskDecorator를 구현해 새로 생성 된 thread에 context를 넘겨줘야한다.
MDC.clear()를 finally에 사용하는 이유는 쓰레드 풀 환경에서 ThreadLocal을 사용하는 경우 ThreadLocal 변수에 보관된 데이터의 사용이 끝나면 반드시 해당 데이터를 삭제해 주어야 한다. 그렇지 않을 경우 재사용되는 쓰레드가 올바르지 않은 데이터를 참조할 수 있다.
TaskDecorator
- thread-pool로 작업(task)를 시작하기 직전에 진행하는 작업을 추가할 수 있도록 하는 interface입니다

import org.springframework.context.annotation.Bean
import org.springframework.context.annotation.Configuration
import org.springframework.core.task.TaskExecutor
import org.springframework.scheduling.annotation.EnableAsync
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor

@Configuration
@EnableAsync
class AsyncConfig {
    @Bean
    fun taskExecutor(): TaskExecutor {
        val taskExecutor = ThreadPoolTaskExecutor()

        // thread pool에 항상 살아있는 thread 최소 갯수
        // thread-pool에서 사용할 수 있는 최대 thread 개수
        // queueCapacity 가 맥스이상의 업무가 몰려오면 큐 개수만큼은 저장해둘 수 있다는 뜻. 단, 그 이상이 들어오면 탈락시켜버린다.
        // cpu 2*(1+80/10)
        // Number of threads = Number of Available Cores * (1 + Wait time / Service time)
        taskExecutor.corePoolSize = 18
        // 18 * 4 = 72
        taskExecutor.maxPoolSize = 72
        // 72 * 4 = 288
        taskExecutor.setQueueCapacity(288)

        taskExecutor.setTaskDecorator(LoggingTaskDecorator())

        taskExecutor.setThreadNamePrefix("logging-thread-")
        taskExecutor.setThreadGroupName("logging-thread-group")
        return taskExecutor
    }
}

스레드를 하드웨어가 가용할 수 있는 것보다 더 많이 사용하게 되면 오히려 더 느려진다. 그래서 thread 숫자를 정확히 기입해서 관리하는 것이 좋다.
corePoolSize
- thread pool에 항상 살아있는 thread 최소 갯수
maxPoolSize
- thread-pool에서 사용할 수 있는 최대 thread 개수
QueueCapacity
- thread-pool에서 사용할 최대 queue 크기
- 맥스 이상의 업무가 몰려오면 큐 개수만큼은 저장해둘 수 있다. 단, 그 이상이 들어오면 탈락시켜 버린다.
쓰레드 커스텀 설정 이유
- 그냥 디폴트 설정으로 사용한다면, 이는 기존의 모든 스레드가 사용 중인 경우 각각의 새 작업이 새 스레드를 생성함을 의미한다.
- 부하가 높은 경우 기껏해야 스레드 "starvation" 상황이 발생하고 최악의 경우 OutOfMemoryError가 발생한다.

Filter vs Interceptor

1. 순서

먼저 순서는 필터가 interceptor 앞단에서 동작한다.

2. 특징 및 차이점

필터란 요청이나 응답이 dispatcher servlet에 도달하기 전이나 후에 그 작업을 처리해주는 역할을 의미한다.
인터셉터란 dispatcher servlet이 controller를 호출하기 전이나 후에 어떤 요청이나 응답을 처리해주는 역할을 의미한다.
필터는 웹 컨테이너가 관리. 인터셉터는 스프링 컨테이너가 관리.
필터는 request와 response 객체를 조작가능. 인터셉터는 불가능.
필터는 공통된 보안, 모든 요청의 로깅 등 spring과 분리되어야 하는 기능
인터셉터는 각 api에 맞는 세부적인 보안, api 호출에 대한 로깅 등
controller로 넘겨주는 데이터의 가공:
- 인터셉터는 HttpServletRequest나 HttpServletResponse 객체를 제공 받아 이 객체 자체를 조작할 수는 없지만 객체의 내부값은 조작할 수 있다. 그래서 controller로 넘겨주는 데이터의 가공이 용이
- filter는 요청 작업의 보안 검사를 전역적으로 하여 올바른 요청이 아닐 경우 차단할 수 있다. 그래서 스프링 컨테이너까지 요청이 전달되지 않게 할 수 있다.(dispatcherServlet 전에 요청을 처리하므로)

() - web context

[] - spring context

client - (filter - [dispatcher servlet - handlerMapping - intercepter - controller - service - repository] )

MDC 설정

import org.apache.logging.log4j.kotlin.logger
import org.slf4j.MDC
import org.springframework.stereotype.Component
import org.springframework.util.ObjectUtils
import org.springframework.web.filter.OncePerRequestFilter
import java.io.IOException
import java.util.*
import javax.servlet.FilterChain
import javax.servlet.ServletException
import javax.servlet.http.HttpServletRequest
import javax.servlet.http.HttpServletResponse

@Component
class LoggingFilter : OncePerRequestFilter() {
    val log = logger("loggingFilter")

    @Throws(ServletException::class, IOException::class)
    override fun doFilterInternal(
        request: HttpServletRequest,
        response: HttpServletResponse,
        filterChain: FilterChain
    ) {
        MDC.clear()

        val ts = System.currentTimeMillis()
        MDC.put(FILTER_APP_TRANSACTION, getTransactionId(request))

        filterChain.doFilter(request, response)

        MDC.put("http-request-method", request.method)
        MDC.put("http-request-uri", getUri(request))
        MDC.put("http-request-ip", Util.getRequestIp(request))
        MDC.put("http-response-status", response.status.toString())
        MDC.put("http-response-time", (System.currentTimeMillis() - ts).toString())

        log.info("{}")
    }

    private fun getUri(request: HttpServletRequest): String {
        return if (ObjectUtils.isEmpty(request.queryString)) {
            request.servletPath
        } else {
            request.servletPath + "?" + request.queryString
        }
    }

    private fun getTransactionId(request: HttpServletRequest): String {
        val transactionId = request.getHeader(FILTER_APP_TRANSACTION)
        return if (!ObjectUtils.isEmpty(transactionId)) transactionId else UUID.randomUUID().toString()
    }
}

MDCAdapter는 interface이고 구현체인 Log4jMDCAdapter를 사용한다.

Filter 선택 이유

필터로 request와 response 객체를 조작가능한 것과 공통된 보안, 모든 요청의 로깅 spring과 분리되어야하는 기능 등 이러한 이유를 근거로 filter를 선택했다.

OncePerRequestFilter vs Filter

1. Filter

매 서블릿마다 호출이 된다.

**서블릿(Servlet)은 클라이언트 요청을 처리하고, 그 결과를 반환하는 웹 프로그래밍 기술

When a request is dispatched using a request dispatcher, it has to go through the filter chain again (or possibly a different one) before it gets to the servlet that is going to deal with it
그래서 위의 의견처럼 filter chain이 두 번 실행될 수 있음. 그래서 나온 것이OncePerRequestFilter 이다.

2. OncePerRequestFilter

사용자의 한 번 요청 당 딱 한 번만 실행되는 필터

받아 볼 로깅 값

transactionId or UUID, http method, request url, request ip, response status, response time

const val FILTER_APP_TRANSACTION = "app-transaction"

String 정의

import javax.servlet.http.HttpServletRequest

object Util {
    fun getRequestIp(request: HttpServletRequest?): String {
        var result = ""

        if (request == null) {
            return result
        }
        val ip = request.getHeader("X-FORWARDED-FOR")
        result = if (ip.isNullOrBlank()) {
            request.remoteAddr
        } else {
            ip.split(",")[0]
        }
        return result
    }
}

ip 주소 리턴 받는 메서드

X-Forwarded-For(XFF)는 XFF 는 HTTP Header 중 하나로 HTTP Server 에 요청한 Client 의 IP 를 식별하기 위한 표준

Logging 사용 방법

import org.apache.logging.log4j.kotlin.logger
import org.springframework.beans.factory.annotation.Value
import org.springframework.http.HttpStatus
import org.springframework.http.ResponseEntity
import org.springframework.web.bind.annotation.GetMapping
import org.springframework.web.bind.annotation.RestController

@RestController
class CheckController {
    val logger = logger("healthCheckName")

    @GetMapping(value = ["/health"])
    fun healthCheck(): ResponseEntity<String> {
        try {
            logger.info("hello world!!")
        } catch (e: Exception) {
            logger.error("error!! ${e.message}",e)
        } finally {
            logger.info("finally!!")
        }
        return ResponseEntity("Spring Boot", HttpStatus.OK)
    }

    fun check() {
        logger.info("without try catch statement!")
    }    
}

try catch finally 문으로 작성할 수도 있다.
그냥 작성할 수도 있다.
상황에 따라 exception이 필요할 때와 필요 없을 때를 구분하여 사용
기본적으로 info를 사용하고, exception에는 error를 사용한다.

Logging Test 방법

@MockMvcTest
class CheckControllerTest {
    @Autowired
    lateinit var mockMvc: MockMvc


    @Test
    @Throws(Exception::class)
    @Async
    fun healthCheckTest() {
        for(i: Int in 1..15) {
            mockMvc.perform(
                MockMvcRequestBuilders.get("/health"))
                .andExpect(status().isOk)
        }
    }
}

Async로 멀티 쓰레드 환경에서 잘 동작하는지 테스트

References

1. 공식문서

https://www.slf4j.org/manual.html

https://logging.apache.org/log4j/kotlin/index.html

https://github.com/apache/logging-log4j-kotlin

https://logging.apache.org/log4j/2.x/performance.html

https://docs.spring.io/spring-boot/docs/2.1.18.RELEASE/reference/html/boot-features-logging.html

https://logback.qos.ch/manual/appenders.html

https://logging.apache.org/log4j/2.x/manual/async.html

https://logging.apache.org/log4j/2.x/manual/layouts.html#PatternLayout

https://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/scheduling/concurrent/ThreadPoolTaskExecutor.html

https://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/core/task/TaskDecorator.html

log4j 공식 문서가 참고한 블로그

https://blog.f12.no/wp/2004/12/09/log4j-and-the-mapped-diagnostic-context/

https://veerasundar.com/blog/log4j-mdc-mapped-diagnostic-context-what-and-why/

2. 개인 or 팀 기술 블로그

https://shplab.tistory.com/entry/log4j-vs-logback-vs-log4j2

https://gmlwjd9405.github.io/2019/01/04/logging-with-slf4j.html

https://xlffm3.github.io/spring%20&%20spring%20boot/async-logger-performance/

https://blog.gangnamunni.com/post/mdc-context-task-decorator/

https://javacan.tistory.com/entry/ThreadLocalUsage

https://engineering.zalando.com/posts/2019/04/how-to-set-an-ideal-thread-pool-size.html

https://pgnt.tistory.com/102

https://minkukjo.github.io/framework/2020/12/18/Spring-142/

https://nowonbun.tistory.com/497

3. stack overflow

https://stackoverflow.com/questions/13152946/what-is-onceperrequestfilter

https://stackoverflow.com/questions/17659510/core-pool-size-vs-maximum-pool-size-in-threadpoolexecutor

'spring' 카테고리의 다른 글

Thymeleaf 작동 구조 (0)	2022.09.06
cors 에러 (0)	2022.07.09
slf4j (0)	2022.06.18
배포방식 (0)	2021.12.17
http와 https 둘 다 운영하는 방법 (0)	2021.12.17

Dexlee Repository

backend logging 시스템 구축

목차

Log 개념정리

1. log란?

2. logging이란?

3. log level

log level 순서

설정 레벨 총 5가지

Logging 왜 필요할까?

Logging Library - Log4j vs Logback vs Log4j2

Log4j

Logback

Log4j2

Logging Dependencies

전체 설정

Log4j2 xml 설정

Properties

Appenders

Loggers

Async Thread 설정

Filter vs Interceptor

MDC 설정

Filter 선택 이유

OncePerRequestFilter vs Filter

받아 볼 로깅 값

Logging 사용 방법

Logging Test 방법

References

'spring' 카테고리의 다른 글

티스토리툴바

backend logging 시스템 구축

목차

Log 개념정리

1. log란?

2. logging이란?

3. log level

log level 순서

설정 레벨 총 5가지

Logging 왜 필요할까?

Logging Library - Log4j vs Logback vs Log4j2

Log4j

Logback

Log4j2

Logging Dependencies

전체 설정

Log4j2 xml 설정

Properties

Appenders

Loggers

Async Thread 설정

Filter vs Interceptor

MDC 설정

Filter 선택 이유

OncePerRequestFilter vs Filter

받아 볼 로깅 값

Logging 사용 방법

Logging Test 방법

References

'spring' 카테고리의 다른 글

'spring' Related Articles

티스토리툴바