🌳FOREST

profileImage

Hi👋, I'm Taeyeon Kim

Logging

CreatedAt: UpdatedAt: 3 min read

Info

  • log4j2로 기본 템플릿 사용
  • filter로 http request/response logging

Log4j

  • src/resources/log4j2.xml 파일로 관리
log4j2.xml
<?xml version="1.0" encoding="UTF-8" ?>  
<Configuration status="INFO">  
    <Properties>  
        <Property name="LOG_DATEFORMAT_PATTERN">{yyyy-MM-dd HH:mm:ss.SSS}</Property>  
        <Property name="LOG_LEVEL_PATTERN">{-%5p}{FATAL=red blink, ERROR=red, WARN=yellow bold, INFO=green, DEBUG=green bold, TRACE=blue} [traceId=%X{traceId}] [userId=%X{userId}] %style{${sys:PID}}{magenta} %style{%F}{blue}:%style{%L}{white} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}</Property>  
    </Properties>  
    <Appenders>  
        <Console name="ConsoleAppender" target="SYSTEM_OUT">  
            <PatternLayout disableAnsi="false" pattern="✈️ %d${LOG_DATEFORMAT_PATTERN} %highlight${LOG_LEVEL_PATTERN}"/>  
        </Console>  
        <RollingFile name="FileAppender"  
                     fileName="logs/spring.log"  
                     filePattern="logs/spring-%d{yyyy-MM-dd}-%i.log">  
            <JsonLayout complete="false" compact="false" charset="UTF-8">  
                <KeyValuePair key="service" value="simple" />  
            </JsonLayout>  
            <Policies>  
                <TimeBasedTriggeringPolicy interval="1" />  
                <SizeBasedTriggeringPolicy size="10000KB" />  
            </Policies>  
            <DefaultRolloverStrategy max="20" fileIndex="min" />  
        </RollingFile>  
    </Appenders>  
    <Loggers>  
        <logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="TRACE" additivity="false">  
            <AppenderRef ref="ConsoleAppender" />  
        </logger>  
  
        <logger name="org.hibernate.SQL" level="DEBUG" additivity="false" >  
            <AppenderRef ref="ConsoleAppender" />  
        </logger>  
        <Logger name="org.springframework.jdbc.datasource.init.ScriptUtils" level="DEBUG" additivity="false">  
            <AppenderRef ref="ConsoleAppender" />  
        </Logger>  
        <Root level="INFO">  
            <AppenderRef ref="ConsoleAppender" />  
        </Root>  
    </Loggers>  
</Configuration>

LoggingFilter

  • src/main/kotlin/com/example/kotlinapiserverguide/commen/filter/LoggingFilter.kt 파일로 관리
  • http request/response 로깅 시, 사용.
  • traceId를 UUID로 생성하여 request에 대한 서비스 로직 추적 (MDC에 추가)
  • request를 받고 response를 수행하기 까지의 startTime/endTime 기록
  • response에 대해서는 json 형태만 로깅. (excludeList 변수 참고)
LogginFilter.kt
package com.example.kotlinapiserverguide.common.filter  
  
import com.example.kotlinapiserverguide.common.filter.domain.HttpLog  
import com.example.kotlinapiserverguide.common.function.logger  
import com.fasterxml.jackson.databind.ObjectMapper  
import com.fasterxml.jackson.module.kotlin.readValue  
import jakarta.servlet.Filter  
import jakarta.servlet.FilterChain  
import jakarta.servlet.ServletRequest  
import jakarta.servlet.ServletResponse  
import jakarta.servlet.http.HttpServletRequest  
import jakarta.servlet.http.HttpServletResponse  
import org.slf4j.MDC  
import org.springframework.web.util.ContentCachingRequestWrapper  
import org.springframework.web.util.ContentCachingResponseWrapper  
import org.springframework.web.util.WebUtils  
import java.io.UnsupportedEncodingException  
import java.util.*  
  
  
class LoggingFilter : Filter {  
    private val log = logger()  
    private val objectMapper: ObjectMapper = ObjectMapper()  
    private val excludeList: List<String> = listOf(  
        "application/javascript",  
        "text/html",  
        "image/x-icon",  
    )  
  
    override fun doFilter(request: ServletRequest?, response: ServletResponse?, chain: FilterChain?) {  
        MDC.put("traceId", UUID.randomUUID().toString())  
  
        val startTime = System.currentTimeMillis()  
        val requestWrapper = ContentCachingRequestWrapper((request as HttpServletRequest))  
        val responseWrapper = ContentCachingResponseWrapper((response as HttpServletResponse?)!!)  
        chain?.doFilter(requestWrapper, responseWrapper)  
        val endTime = System.currentTimeMillis()  
        val elapsedTime = (endTime - startTime) / 1000.0  
        val httpLog = objectMapper.writeValueAsString(createHttpLog(requestWrapper, elapsedTime, responseWrapper))  
        log.info("[HTTP] - $httpLog")  
  
        MDC.clear()  
    }  
  
    private fun createHttpLog(  
        requestWrapper: ContentCachingRequestWrapper,  
        elapsedTime: Double,  
        responseWrapper: ContentCachingResponseWrapper  
    ): HttpLog {  
        return HttpLog(  
            HttpLog.Request(  
                requestWrapper.requestURL.toString(),  
                requestWrapper.method,  
                requestWrapper.servletPath,  
                elapsedTime,  
                getRequestHeaders(requestWrapper),  
                requestWrapper.queryString,  
                getRequestBody(requestWrapper)  
            ),  
            HttpLog.Response(  
                responseWrapper.status.toString(),  
                getResponseHeaders(responseWrapper),  
                getResponseBody(responseWrapper)  
            )  
        )  
    }  
  
    private fun getRequestHeaders(request: HttpServletRequest): Map<String, Any?> {  
        val headers: MutableMap<String, Any?> = mutableMapOf()  
        val headerNames: Enumeration<String> = request.headerNames  
        while (headerNames.hasMoreElements()) {  
            val headerName: String = headerNames.nextElement()  
            headers[headerName] = request.getHeader(headerName)  
        }  
        return headers  
    }  
  
    private fun getRequestBody(request: ContentCachingRequestWrapper): Map<String, Any?>? {  
        val wrapper = WebUtils.getNativeRequest(  
            request,  
            ContentCachingRequestWrapper::class.java  
        )  
        try {  
            if (wrapper != null) {  
                val buf = wrapper.contentAsByteArray  
                if (buf.isNotEmpty()) {  
                    val jsonString = String(buf, 0, buf.size, charset(wrapper.characterEncoding))  
                    return objectMapper.readValue<Map<String, Any?>>(jsonString)  
                }  
            }  
        } catch (e: UnsupportedEncodingException) {  
            return null  
        } catch (e: Exception) {  
            return null  
        }  
        return null  
    }  
  
    private fun getResponseHeaders(response: HttpServletResponse): MutableMap<String, Any> {  
        val headers: MutableMap<String, Any> = mutableMapOf()  
        val headerNames: MutableCollection<String> = response.headerNames  
        headerNames.forEach { headerName ->  
            headers[headerName] = response.getHeader(headerName)  
        }  
        return headers  
    }  
  
    private fun getResponseBody(response: HttpServletResponse): Map<String, Any?>? {  
        var payload: String? = null  
  
        val wrapper = WebUtils.getNativeResponse(response, ContentCachingResponseWrapper::class.java)  
        if (wrapper != null) {  
            val buffer: ByteArray = wrapper.contentAsByteArray  
            if (buffer.isNotEmpty()) {  
                payload = buffer.toString(Charsets.UTF_8)  
                wrapper.copyBodyToResponse()  
  
                if (response.contentType != null) {  
                    val isMatch: Boolean = excludeList.stream()  
                        .anyMatch { exclude -> response.contentType.contains(exclude) }  
                    if (isMatch) return null  
                }  
  
                return objectMapper.readValue<Map<String, Any?>>(payload)  
            }  
        }  
        return null  
    }  
  
}

Sample

  • 실제 로깅 시에는 제외 대상을 선별할 계획
sample.log
✈️ 2025-02-21 16:06:06.501 - INFO [traceId=4989cc04-2499-4030-b344-3321f5cf334d] [userId=] 45860 LoggingFilter.kt:40 : [HTTP] - {"request":{"url":"http://127.0.0.1:8000/api/user/login","method":"POST","path":"/api/user/login","elapsedTime":0.577,"headers":{"content-type":"application/json","content-length":"46","user-agent":"IntelliJ HTTP Client/IntelliJ IDEA 2024.3.3","accept-encoding":"br, deflate, gzip, x-gzip","accept":"*/*","host":"127.0.0.1:8000"},"queryString":null,"body":{"username":"test","password":"test"}},"response":{"status":"200","headers":{"Vary":"Origin","X-Content-Type-Options":"nosniff","X-XSS-Protection":"0","Cache-Control":"no-cache, no-store, max-age=0, must-revalidate","Pragma":"no-cache","Expires":"0","X-Frame-Options":"DENY"},"body":{"resultCode":"SUCCESS","resultMessage":"success.","body":{"accessToken":"eyJhbGciOiJIUzUxMiJ9.eyJzdWIiOiIxIiwiaWF0IjoxNzQwMTIxNTY2LCJleHAiOjE3NDE0MTc1NjZ9.Xqf8O4jKezwSw1GacyEpxVVgnt9tTJl7-9SOXfIC89aRTsM3ixOzE0TdK_KLwWa_avO8USK-fvDpcgz8YCL85Q","refreshToken":"eyJhbGciOiJIUzUxMiJ9.eyJzdWIiOiIxIiwiaWF0IjoxNzQwMTIxNTY2LCJleHAiOjE3NDI3MTM1NjZ9.vyYrQuAEflGLT_cKCWqjf5Zllk-ZO5c4RvLzm8AedDsCN-rsSmrbl9pA7I00N3L0S6vcYEmv_thM1coVXu0Oqg"}}}}

Graph View