Merge branch 'feature/DRAW-240' into sandbox

.gitignore

@@ -1,4 +1,4 @@
-log/
+/log
 .gradle
 build/
 !gradle/wrapper/gradle-wrapper.jar

app/api/src/main/kotlin/com/xorker/draw/log/ApiLoggingFilter.kt

@@ -1,63 +1,61 @@
 package com.xorker.draw.log
 
+import com.fasterxml.jackson.databind.ObjectMapper
+import com.xorker.draw.support.logging.defaultApiJsonMap
 import com.xorker.draw.support.logging.logger
+import com.xorker.draw.support.logging.registerRequestId
 import jakarta.servlet.Filter
 import jakarta.servlet.FilterChain
 import jakarta.servlet.ServletRequest
 import jakarta.servlet.ServletResponse
 import jakarta.servlet.annotation.WebFilter
 import jakarta.servlet.http.HttpServletRequest
 import jakarta.servlet.http.HttpServletResponse
+import org.slf4j.MDC
 import org.springframework.core.Ordered
 import org.springframework.core.annotation.Order
+import org.springframework.stereotype.Component
+import org.springframework.web.util.ContentCachingRequestWrapper
 import org.springframework.web.util.ContentCachingResponseWrapper
 
+@Component
 @WebFilter(urlPatterns = ["/api/*"])
 @Order(Ordered.HIGHEST_PRECEDENCE)
-class ApiLoggingFilter : Filter {
+class ApiLoggingFilter(
+    private val objectMapper: ObjectMapper,
+) : Filter {
     private val logger = logger()
 
     override fun doFilter(servletRequest: ServletRequest, servletResponse: ServletResponse, chain: FilterChain) {
-        val request = RequestLoggingWrapper(servletRequest as HttpServletRequest)
-        val response = getResponseWrapper(servletResponse as HttpServletResponse)
+        registerRequestId()
+        val request = ContentCachingRequestWrapper(servletRequest as HttpServletRequest)
+        val response = ContentCachingResponseWrapper(servletResponse as HttpServletResponse)
 
         try {
             chain.doFilter(request, response)
         } finally {
-            logger.info("${generateRequestLog(request)}\n${generateResponseLog(response)}")
+            logger.info(generateLog(request, response))
             response.copyBodyToResponse()
         }
     }
 
-    private fun generateRequestLog(request: HttpServletRequest): String {
-        val log = StringBuilder("[Req]\n${request.method} ${request.requestURI}")
+    private fun generateLog(request: ContentCachingRequestWrapper, response: ContentCachingResponseWrapper): String {
+        val data = defaultApiJsonMap(
+            // Request 부분
+            "method" to request.method,
+            "uri" to request.requestURI,
+            "query" to request.queryString,
+            "header" to request.headerNames.asSequence().map { it to request.getHeader(it) }.toMap(),
+            "requestBody" to request.contentAsString,
 
-        if (request.queryString.isNullOrBlank().not()) {
-            log.append("?${request.queryString}")
-        }
-
-        request.headerNames.iterator().forEach {
-            log.append("\n$it=${request.getHeader(it)}")
-        }
-
-        request.reader.lines().forEach {
-            log.append("\n$it")
-        }
+            // Response 부분
+            "status" to response.status,
+            "responseBody" to String(response.contentAsByteArray),
 
-        return log.toString()
-    }
-
-    private fun generateResponseLog(response: ContentCachingResponseWrapper): String {
-        val log = StringBuilder("[Res]\n${response.status}")
-
-        val responseCacheWrapperObject = getResponseWrapper(response)
+            "requestId" to MDC.get("requestId"),
+            "userId" to MDC.get("userId"),
+        )
 
-        val responseStr = String(responseCacheWrapperObject.contentAsByteArray)
-
-        log.append("\n$responseStr")
-        return log.toString()
+        return objectMapper.writeValueAsString(data)
     }
-
-    private fun getResponseWrapper(response: HttpServletResponse): ContentCachingResponseWrapper =
-        response as? ContentCachingResponseWrapper ?: ContentCachingResponseWrapper(response)
 }

app/support/auth/src/main/kotlin/com/xorker/draw/support/auth/security/TokenAuthenticationFilter.kt

@@ -5,6 +5,7 @@ import com.xorker.draw.user.UserId
 import jakarta.servlet.FilterChain
 import jakarta.servlet.http.HttpServletRequest
 import jakarta.servlet.http.HttpServletResponse
+import org.slf4j.MDC
 import org.springframework.security.core.context.SecurityContextHolder
 import org.springframework.security.web.authentication.WebAuthenticationDetailsSource
 import org.springframework.stereotype.Component
@@ -22,6 +23,7 @@ internal class TokenAuthenticationFilter(
         val accessToken = getAccessToken(request)
         if (accessToken != null) {
             tokenUseCase.getUserId(accessToken)?.let {
+                MDC.put("userId", it.value.toString())
                 setAuthentication(request, accessToken, it)
             }
         }

app/websocket/src/main/kotlin/com/xorker/draw/websocket/MainWebSocketHandler.kt

@@ -2,6 +2,7 @@ package com.xorker.draw.websocket
 
 import com.xorker.draw.exception.XorkerException
 import com.xorker.draw.websocket.exception.WebSocketExceptionHandler
+import com.xorker.draw.websocket.log.WebSocketLogger
 import com.xorker.draw.websocket.parser.WebSocketRequestParser
 import org.springframework.stereotype.Component
 import org.springframework.web.socket.CloseStatus
@@ -16,21 +17,26 @@ class MainWebSocketHandler(
     private val requestParser: WebSocketRequestParser,
     private val sessionEventListener: List<SessionEventListener>,
     private val webSocketExceptionHandler: WebSocketExceptionHandler,
+    private val webSocketLogger: WebSocketLogger,
 ) : TextWebSocketHandler() {
     override fun afterConnectionEstablished(session: WebSocketSession) {
+        webSocketLogger.afterConnectionEstablished(session)
     }
 
     override fun handleTextMessage(session: WebSocketSession, message: TextMessage) {
         val request = requestParser.parse(message.payload)
 
-        try {
-            router.route(session, request)
-        } catch (ex: XorkerException) {
-            webSocketExceptionHandler.handleXorkerException(session, request.action, ex)
+        webSocketLogger.handleRequest(session, request) { s, req ->
+            try {
+                router.route(s, req)
+            } catch (ex: XorkerException) {
+                webSocketExceptionHandler.handleXorkerException(s, req.action, ex)
+            }
         }
     }
 
     override fun afterConnectionClosed(session: WebSocketSession, status: CloseStatus) {
+        webSocketLogger.afterConnectionClosed(session, status)
         val sessionDto = sessionUseCase.getSession(SessionId(session.id)) ?: return // TODO error logging
 
         when (status) {

app/websocket/src/main/kotlin/com/xorker/draw/websocket/log/WebSocketLogger.kt

@@ -0,0 +1,74 @@
+package com.xorker.draw.websocket.log
+
+import com.fasterxml.jackson.databind.ObjectMapper
+import com.xorker.draw.support.logging.defaultApiJsonMap
+import com.xorker.draw.support.logging.logger
+import com.xorker.draw.support.logging.registerRequestId
+import com.xorker.draw.websocket.SessionId
+import com.xorker.draw.websocket.SessionUseCase
+import com.xorker.draw.websocket.message.request.dto.WebSocketRequest
+import org.springframework.stereotype.Component
+import org.springframework.web.socket.CloseStatus
+import org.springframework.web.socket.WebSocketSession
+
+@Component
+class WebSocketLogger(
+    private val sessionUseCase: SessionUseCase,
+    private val objectMapper: ObjectMapper,
+) {
+    private val logger = logger()
+
+    fun afterConnectionEstablished(session: WebSocketSession) {
+        logger.info(
+            objectMapper.writeValueAsString(
+                defaultApiJsonMap(
+                    "action" to "WS_CONNECT",
+                    "sessionId" to session.id,
+                ),
+            ),
+        )
+    }
+
+    fun handleRequest(session: WebSocketSession, request: WebSocketRequest, origin: (WebSocketSession, WebSocketRequest) -> Unit) {
+        registerRequestId()
+        try {
+            origin(session, request)
+        } finally {
+            val log = generateLog(SessionId(session.id), request)
+            logger.info(log)
+        }
+    }
+
+    private fun generateLog(sessionId: SessionId, request: WebSocketRequest): String {
+        val data = defaultApiJsonMap(
+            "action" to request.action,
+            "requestBody" to request.body,
+            "sessionId" to sessionId.value,
+        )
+
+        val session = sessionUseCase.getSession(sessionId)
+        if (session != null) {
+            data["userId"] = session.user.id.value
+            data["roomId"] = session.roomId
+        }
+
+        return objectMapper.writeValueAsString(data)
+    }
+
+    fun afterConnectionClosed(session: WebSocketSession, status: CloseStatus) {
+        val data = defaultApiJsonMap(
+            "action" to "WS_CLOSED",
+            "status" to status,
+            "sessionId" to session.id,
+        )
+
+        val sessionDto = sessionUseCase.getSession(SessionId(session.id))
+        if (sessionDto != null) {
+            data["userId"] = sessionDto.user.id.value
+            data["roomId"] = sessionDto.roomId
+        }
+
+        val log = objectMapper.writeValueAsString(data)
+        logger.info(log)
+    }
+}

support/logging/src/main/kotlin/com/xorker/draw/support/logging/Logger.kt

@@ -1,6 +1,25 @@
 package com.xorker.draw.support.logging
 
+import java.time.LocalDateTime
+import java.time.format.DateTimeFormatter
+import java.util.UUID
 import org.slf4j.Logger
 import org.slf4j.LoggerFactory
+import org.slf4j.MDC
 
 inline fun <reified T> T.logger(): Logger = LoggerFactory.getLogger(T::class.java)
+
+fun registerRequestId() {
+    MDC.put("requestId", UUID.randomUUID().toString())
+}
+
+private val TIMESTAMP_FORMATTER = DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSSXXX")
+fun defaultApiJsonMap(vararg pairs: Pair<String, Any?>): MutableMap<String, Any?> {
+    val now = LocalDateTime.now()
+
+    val map = mutableMapOf(*pairs)
+
+    map["timestamp"] = TIMESTAMP_FORMATTER.format(now)
+
+    return map
+}

support/logging/src/main/kotlin/com/xorker/draw/support/logging/XorkerJsonLayout.kt

@@ -3,6 +3,7 @@ package com.xorker.draw.support.logging
 import ch.qos.logback.classic.spi.ILoggingEvent
 import ch.qos.logback.contrib.jackson.JacksonJsonFormatter
 import ch.qos.logback.contrib.json.classic.JsonLayout
+import org.slf4j.MDC
 
 class XorkerJsonLayout : JsonLayout() {
 
@@ -21,5 +22,14 @@ class XorkerJsonLayout : JsonLayout() {
 
     override fun addCustomDataToJsonMap(map: MutableMap<String, Any>, event: ILoggingEvent) {
         super.addCustomDataToJsonMap(map, event)
+
+        MDC_LIST.forEach { key ->
+            MDC.get(key)?.let { value -> map[key] = value }
+        }
+    }
+
+    companion object {
+        // MDC에서 Json에 넣을 목록
+        private val MDC_LIST = listOf("requestId", "userId")
     }
 }

support/logging/src/main/resources/logback-appender.xml

@@ -52,7 +52,7 @@
     <appender name="WS_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}/ws.log</file>
         <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
-            <fileNamePattern>${LOG_PATH}/ws-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
+            <fileNamePattern>${LOG_PATH}/ws/${HOSTNAME}-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
             <maxFileSize>20MB</maxFileSize>
             <maxHistory>7</maxHistory>
             <totalSizeCap>100MB</totalSizeCap>

support/logging/src/main/resources/logback-dev.xml

@@ -11,6 +11,11 @@
         <appender-ref ref="API_FILE"/>
     </logger>
 
+    <logger name="com.xorker.draw.websocket.log.WebSocketLogger" level="INFO" additivity="false">
+        <appender-ref ref="WS_FILE"/>
+    </logger>
+
+
     <logger name="org.hibernate" level="ERROR"/>
     <logger name="org.springframework.web" level="INFO"/>
 </configuration>

support/logging/src/main/resources/logback-local.xml

@@ -9,6 +9,12 @@
 
     <logger name="com.xorker.draw.log.ApiLoggingFilter" level="INFO" additivity="false">
         <appender-ref ref="API_CONSOLE"/>
+        <appender-ref ref="API_FILE"/>
+    </logger>
+
+    <logger name="com.xorker.draw.websocket.log.WebSocketLogger" level="INFO" additivity="false">
+        <appender-ref ref="WS_CONSOLE"/>
+        <appender-ref ref="WS_FILE"/>
     </logger>
 
     <logger name="org.hibernate" level="ERROR"/>

support/logging/src/main/resources/logback-production.xml

@@ -11,6 +11,10 @@
         <appender-ref ref="API_FILE"/>
     </logger>
 
+    <logger name="com.xorker.draw.websocket.log.WebSocketLogger" level="INFO" additivity="false">
+        <appender-ref ref="WS_FILE"/>
+    </logger>
+
     <logger name="org.hibernate" level="ERROR"/>
     <logger name="org.springframework.web" level="INFO"/>
 </configuration>