diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 9819625..2a43438 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -31,6 +31,7 @@ jjwt-api = { module = "io.jsonwebtoken:jjwt-api", version.ref = "jjwt" } jjwt-impl = { module = "io.jsonwebtoken:jjwt-impl", version.ref = "jjwt" } jjwt-jackson = { module = "io.jsonwebtoken:jjwt-jackson", version.ref = "jjwt" } springdoc-openapi-webmvc-ui = { module = "org.springdoc:springdoc-openapi-starter-webmvc-ui", version.ref = "springdoc" } +micrometer-context-propagation = { module = "io.micrometer:context-propagation" } mockk = { module = "io.mockk:mockk", version.ref = "mockk" } [plugins] diff --git a/rush-gateway/README.md b/rush-gateway/README.md index b2fcfbd..68ac10e 100644 --- a/rush-gateway/README.md +++ b/rush-gateway/README.md @@ -39,6 +39,16 @@ WebSocket을 제외한 라우트는 서킷브레이커를 거칩니다. 서비 - WebSocket용 `?token=`은 검증이 끝나면 지우고 서비스로 넘깁니다. - 각 서비스의 `/{prefix}/v3/api-docs`는 토큰 없이 접근할 수 있습니다. +## 로그 + +로그는 JSON 한 줄(logstash 형식)로 stdout에 남깁니다. 요청마다 `X-Request-Id`를 새로 만들어 서비스와 응답에 넘깁니다. 접근 로그는 요청이 끝날 때 한 줄씩 남깁니다. + +```json +{"message":"GET /user/ping 200 4ms","requestId":"18e0…","userId":"42","clientIp":"127.0.0.1","method":"GET","path":"/user/ping","status":200,"latencyMs":4,"routeId":"rush-user"} +``` + +`requestId`, `userId`, `clientIp`는 MDC로 이어지므로, 요청 처리 중 남긴 다른 로그에도 들어갑니다. + | 환경변수 | 기본값 | 설명 | |---|---|---| | `GATEWAY_ADMIN_ALLOWED_IPS` | `127.0.0.1/32,::1/128` | 관리용 actuator 허용 대역 | diff --git a/rush-gateway/build.gradle.kts b/rush-gateway/build.gradle.kts index b4eaf93..af869af 100644 --- a/rush-gateway/build.gradle.kts +++ b/rush-gateway/build.gradle.kts @@ -9,6 +9,7 @@ dependencies { implementation(libs.spring.cloud.starter.netflix.eureka.client) implementation(libs.spring.boot.starter.actuator) implementation(libs.spring.boot.starter.security) + implementation(libs.micrometer.context.propagation) implementation(libs.jjwt.api) runtimeOnly(libs.jjwt.impl) runtimeOnly(libs.jjwt.jackson) diff --git a/rush-gateway/src/main/kotlin/com/rush/gateway/error/GlobalErrorHandler.kt b/rush-gateway/src/main/kotlin/com/rush/gateway/error/GlobalErrorHandler.kt index d8a08d4..1463e47 100644 --- a/rush-gateway/src/main/kotlin/com/rush/gateway/error/GlobalErrorHandler.kt +++ b/rush-gateway/src/main/kotlin/com/rush/gateway/error/GlobalErrorHandler.kt @@ -1,5 +1,6 @@ package com.rush.gateway.error +import com.rush.gateway.logging.RequestContext import org.slf4j.LoggerFactory import org.springframework.boot.web.reactive.error.ErrorWebExceptionHandler import org.springframework.core.annotation.Order @@ -26,7 +27,10 @@ class GlobalErrorHandler( val status = statusOf(ex) if (status.is5xxServerError) { - log.error("요청 처리 실패 {} {}", exchange.request.method, exchange.request.path, ex) + // 이 핸들러는 WebFilter 체인 바깥이라 Reactor context가 없으므로 exchange에서 MDC를 채웁니다. + RequestContext.withMdc(exchange) { + log.error("요청 처리 실패 {} {}", exchange.request.method, exchange.request.path, ex) + } } return writer.write(exchange, status) } diff --git a/rush-gateway/src/main/kotlin/com/rush/gateway/filter/AccessLogFilter.kt b/rush-gateway/src/main/kotlin/com/rush/gateway/filter/AccessLogFilter.kt index 16ac557..56978e9 100644 --- a/rush-gateway/src/main/kotlin/com/rush/gateway/filter/AccessLogFilter.kt +++ b/rush-gateway/src/main/kotlin/com/rush/gateway/filter/AccessLogFilter.kt @@ -1,17 +1,27 @@ package com.rush.gateway.filter +import com.rush.gateway.logging.RequestContext +import com.rush.gateway.security.ClientIpResolver import org.slf4j.LoggerFactory +import org.springframework.cloud.gateway.route.Route +import org.springframework.cloud.gateway.support.ServerWebExchangeUtils.GATEWAY_ROUTE_ATTR import org.springframework.core.Ordered import org.springframework.stereotype.Component import org.springframework.web.server.ServerWebExchange import org.springframework.web.server.WebFilter import org.springframework.web.server.WebFilterChain import reactor.core.publisher.Mono +import reactor.util.context.Context import java.util.UUID +/** + * 가장 바깥 필터입니다. 요청마다 X-Request-Id를 새로 만들어 서비스와 응답에 넘기고, + * 요청이 끝나면 접근 로그를 한 줄 남깁니다. 400·401·403 같은 게이트웨이 응답도 기록됩니다. + */ @Component -class AccessLogFilter : - WebFilter, +class AccessLogFilter( + private val clientIpResolver: ClientIpResolver, +) : WebFilter, Ordered { private val log = LoggerFactory.getLogger(javaClass) @@ -20,27 +30,46 @@ class AccessLogFilter : chain: WebFilterChain, ): Mono { val requestId = UUID.randomUUID().toString() + val clientIp = clientIpResolver.resolve(exchange.request) + RequestContext.put(exchange, RequestContext.REQUEST_ID, requestId) + RequestContext.put(exchange, RequestContext.CLIENT_IP, clientIp) + val request = exchange.request .mutate() .headers { it.set(REQUEST_ID_HEADER, requestId) } .build() exchange.response.headers.set(REQUEST_ID_HEADER, requestId) + val mutated = exchange.mutate().request(request).build() + val context = Context.of(RequestContext.REQUEST_ID, requestId, RequestContext.CLIENT_IP, clientIp) val path = exchange.request.path.value() - if (path.startsWith("/actuator/")) return chain.filter(exchange.mutate().request(request).build()) + if (path.startsWith("/actuator/")) return chain.filter(mutated).contextWrite(context) val start = System.nanoTime() - return chain.filter(exchange.mutate().request(request).build()).doFinally { - log.info( - "{} {} {} {}ms requestId={} userId={}", - exchange.request.method, - path, - exchange.response.statusCode?.value(), - (System.nanoTime() - start) / 1_000_000, - requestId, - exchange.getAttribute(JwtAuthenticationFilter.USER_ID_HEADER) ?: "-", - ) + return chain + .filter(mutated) + .doFinally { log(exchange, path, start) } + .contextWrite(context) + } + + private fun log( + exchange: ServerWebExchange, + path: String, + start: Long, + ) { + val status = exchange.response.statusCode?.value() + val latencyMs = (System.nanoTime() - start) / 1_000_000 + val routeId = exchange.getAttribute(GATEWAY_ROUTE_ATTR)?.id + RequestContext.withMdc(exchange) { + log + .atInfo() + .addKeyValue("method", exchange.request.method.name()) + .addKeyValue("path", path) + .addKeyValue("status", status) + .addKeyValue("latencyMs", latencyMs) + .addKeyValue("routeId", routeId ?: "-") + .log("{} {} {} {}ms", exchange.request.method, path, status, latencyMs) } } diff --git a/rush-gateway/src/main/kotlin/com/rush/gateway/filter/JwtAuthenticationFilter.kt b/rush-gateway/src/main/kotlin/com/rush/gateway/filter/JwtAuthenticationFilter.kt index 28b563b..d69b3b0 100644 --- a/rush-gateway/src/main/kotlin/com/rush/gateway/filter/JwtAuthenticationFilter.kt +++ b/rush-gateway/src/main/kotlin/com/rush/gateway/filter/JwtAuthenticationFilter.kt @@ -1,6 +1,7 @@ package com.rush.gateway.filter import com.rush.gateway.error.ErrorResponseWriter +import com.rush.gateway.logging.RequestContext import io.jsonwebtoken.Jwts import io.jsonwebtoken.security.Keys import org.springframework.beans.factory.annotation.Value @@ -63,6 +64,7 @@ class JwtAuthenticationFilter( }.getOrNull() ?: return unauthorized(exchange) exchange.attributes[USER_ID_HEADER] = userId + RequestContext.put(exchange, RequestContext.USER_ID, userId) // 쿼리로 받은 토큰은 검증이 끝났으므로 서비스 쪽 로그에 남지 않게 지웁니다. val authed = sanitized @@ -70,7 +72,9 @@ class JwtAuthenticationFilter( .uri(withoutTokenQuery(request.uri)) .header(USER_ID_HEADER, userId) .build() - return chain.filter(exchange.mutate().request(authed).build()) + return chain + .filter(exchange.mutate().request(authed).build()) + .contextWrite { it.put(RequestContext.USER_ID, userId) } } // 인증은 디코딩된 키로 토큰을 읽으므로, ?%74oken=처럼 인코딩된 키도 디코딩한 뒤 비교해 지웁니다. diff --git a/rush-gateway/src/main/kotlin/com/rush/gateway/logging/MdcContextPropagationConfig.kt b/rush-gateway/src/main/kotlin/com/rush/gateway/logging/MdcContextPropagationConfig.kt new file mode 100644 index 0000000..cfafdac --- /dev/null +++ b/rush-gateway/src/main/kotlin/com/rush/gateway/logging/MdcContextPropagationConfig.kt @@ -0,0 +1,23 @@ +package com.rush.gateway.logging + +import io.micrometer.context.ContextRegistry +import org.slf4j.MDC +import org.springframework.context.annotation.Configuration + +/** + * Reactor context에 넣은 요청 추적 값을 로그 MDC로 옮기도록 등록합니다. + * spring.reactor.context-propagation=auto와 함께 쓰여, 스레드가 바뀌어도 MDC가 이어집니다. + */ +@Configuration(proxyBeanMethods = false) +class MdcContextPropagationConfig { + init { + RequestContext.KEYS.forEach { key -> + ContextRegistry.getInstance().registerThreadLocalAccessor( + key, + { MDC.get(key) }, + { value: String -> MDC.put(key, value) }, + { MDC.remove(key) }, + ) + } + } +} diff --git a/rush-gateway/src/main/kotlin/com/rush/gateway/logging/RequestContext.kt b/rush-gateway/src/main/kotlin/com/rush/gateway/logging/RequestContext.kt new file mode 100644 index 0000000..48b9c5c --- /dev/null +++ b/rush-gateway/src/main/kotlin/com/rush/gateway/logging/RequestContext.kt @@ -0,0 +1,47 @@ +package com.rush.gateway.logging + +import org.slf4j.MDC +import org.springframework.web.server.ServerWebExchange + +/** + * 요청 하나를 추적하는 값(requestId, userId, clientIp)의 키와 보관 방법을 모아 둡니다. + * + * WebFilter 체인 안의 로그는 Reactor context → MDC 전파로 이 값을 자동으로 갖습니다. + * 체인 바깥(ErrorWebExceptionHandler 등)에서는 exchange attribute를 읽어 [withMdc]로 남깁니다. + */ +object RequestContext { + const val REQUEST_ID = "requestId" + const val USER_ID = "userId" + const val CLIENT_IP = "clientIp" + + val KEYS = listOf(REQUEST_ID, USER_ID, CLIENT_IP) + + private fun attribute(key: String) = "rush.gateway.$key" + + fun put( + exchange: ServerWebExchange, + key: String, + value: String, + ) { + exchange.attributes[attribute(key)] = value + } + + fun get( + exchange: ServerWebExchange, + key: String, + ): String? = exchange.getAttribute(attribute(key)) + + /** exchange에 저장된 값을 MDC에 넣은 채로 [block]을 실행합니다. */ + fun withMdc( + exchange: ServerWebExchange, + block: () -> T, + ): T { + val previous = MDC.getCopyOfContextMap() + KEYS.forEach { key -> get(exchange, key)?.let { MDC.put(key, it) } } + try { + return block() + } finally { + if (previous == null) MDC.clear() else MDC.setContextMap(previous) + } + } +} diff --git a/rush-gateway/src/main/resources/application.yml b/rush-gateway/src/main/resources/application.yml index 0a5c8c0..d2046c3 100644 --- a/rush-gateway/src/main/resources/application.yml +++ b/rush-gateway/src/main/resources/application.yml @@ -8,6 +8,9 @@ spring: name: rush-gateway config: import: optional:configserver:${CONFIG_URL:http://localhost:8888} + reactor: + # Reactor context의 requestId·userId·clientIp를 로그 MDC로 이어 줍니다. + context-propagation: auto autoconfigure: # 로그인 사용자가 없으므로 기본 사용자와 임시 비밀번호를 만들지 않습니다. exclude: org.springframework.boot.autoconfigure.security.reactive.ReactiveUserDetailsServiceAutoConfiguration @@ -110,3 +113,9 @@ management: gateway: # SCG 기본값은 none(꺼짐)입니다. 라우트 조회만 열고 생성·삭제·refresh는 막습니다. access: read-only + +# 로그를 JSON 한 줄로 남깁니다. MDC(requestId, userId, clientIp)와 접근 로그 필드가 그대로 들어갑니다. +logging: + structured: + format: + console: logstash diff --git a/rush-gateway/src/test/kotlin/com/rush/gateway/logging/AccessLogTest.kt b/rush-gateway/src/test/kotlin/com/rush/gateway/logging/AccessLogTest.kt new file mode 100644 index 0000000..fb272db --- /dev/null +++ b/rush-gateway/src/test/kotlin/com/rush/gateway/logging/AccessLogTest.kt @@ -0,0 +1,139 @@ +package com.rush.gateway.logging + +import com.fasterxml.jackson.databind.JsonNode +import com.fasterxml.jackson.databind.ObjectMapper +import com.sun.net.httpserver.HttpServer +import io.jsonwebtoken.Jwts +import io.jsonwebtoken.security.Keys +import org.assertj.core.api.Assertions.assertThat +import org.junit.jupiter.api.AfterAll +import org.junit.jupiter.api.Test +import org.junit.jupiter.api.extension.ExtendWith +import org.springframework.beans.factory.annotation.Autowired +import org.springframework.boot.test.context.SpringBootTest +import org.springframework.boot.test.system.CapturedOutput +import org.springframework.boot.test.system.OutputCaptureExtension +import org.springframework.test.context.DynamicPropertyRegistry +import org.springframework.test.context.DynamicPropertySource +import org.springframework.test.web.reactive.server.WebTestClient +import java.net.InetSocketAddress +import java.net.ServerSocket +import java.time.Duration + +private const val SECRET = "test-secret-key-for-gateway-access-log-test-0123456789" + +// clientIp를 확인하려면 remoteAddress가 필요하므로 실제 서버(RANDOM_PORT)로 요청합니다. +@ExtendWith(OutputCaptureExtension::class) +@SpringBootTest( + webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT, + properties = [ + "spring.cloud.config.enabled=false", + "eureka.client.enabled=false", + "jwt.secret=$SECRET", + ], +) +class AccessLogTest { + @Autowired + lateinit var client: WebTestClient + + private val objectMapper = ObjectMapper() + + @Test + fun `요청마다 JSON 접근 로그를 한 줄 남긴다`(output: CapturedOutput) { + val requestId = requestIdOf("/user/ping", token("42")) + + val line = + awaitLine(output) { + it.path("requestId").asText() == requestId && + it.path("logger_name").asText().endsWith("AccessLogFilter") + } + assertThat(line.path("userId").asText()).isEqualTo("42") + assertThat(line.path("clientIp").asText()).isEqualTo("127.0.0.1") + assertThat(line.path("routeId").asText()).isEqualTo("rush-user") + assertThat(line.path("status").asInt()).isEqualTo(200) + assertThat(line.path("method").asText()).isEqualTo("GET") + assertThat(line.path("path").asText()).isEqualTo("/user/ping") + } + + @Test + fun `게이트웨이가 거절한 요청도 접근 로그에 남는다`(output: CapturedOutput) { + val requestId = requestIdOf("/user/ping", token = null) + + val line = awaitLine(output) { it.path("requestId").asText() == requestId && it.has("status") } + assertThat(line.path("status").asInt()).isEqualTo(401) + } + + @Test + fun `라우트 처리 중 남긴 로그에도 MDC가 이어진다`(output: CapturedOutput) { + val requestId = requestIdOf("/sp/ping", token("7")) + + val fallbackLog = awaitLine(output) { it.path("logger_name").asText().endsWith("FallbackController") } + assertThat(fallbackLog.path("requestId").asText()).isEqualTo(requestId) + assertThat(fallbackLog.path("userId").asText()).isEqualTo("7") + } + + private fun requestIdOf( + uri: String, + token: String?, + ): String = + client + .get() + .uri(uri) + .apply { if (token != null) header("Authorization", "Bearer $token") } + .exchange() + .returnResult(String::class.java) + .responseHeaders + .getFirst("X-Request-Id")!! + + // 접근 로그는 응답을 보낸 뒤 doFinally에서 남으므로, 나타날 때까지 잠시 기다립니다. + private fun awaitLine( + output: CapturedOutput, + predicate: (JsonNode) -> Boolean, + ): JsonNode { + val deadline = System.nanoTime() + Duration.ofSeconds(2).toNanos() + while (true) { + jsonLines(output).singleOrNull(predicate)?.let { return it } + if (System.nanoTime() > deadline) return jsonLines(output).single(predicate) + Thread.sleep(20) + } + } + + private fun jsonLines(output: CapturedOutput): List = + output.out + .lines() + .filter { it.startsWith("{") } + .map { objectMapper.readTree(it) } + + companion object { + private val okServer = + HttpServer.create(InetSocketAddress("localhost", 0), 0).apply { + createContext("/") { exchange -> + exchange.sendResponseHeaders(200, -1) + exchange.close() + } + start() + } + + private val closedPort = ServerSocket(0).use { it.localPort } + + @JvmStatic + @DynamicPropertySource + fun routes(registry: DynamicPropertyRegistry) { + registry.add("USER_URL") { "http://localhost:${okServer.address.port}" } + registry.add("SP_URL") { "http://localhost:$closedPort" } + } + + @JvmStatic + @AfterAll + fun stopServer() { + okServer.stop(0) + } + + private fun token(subject: String): String = + Jwts + .builder() + .subject(subject) + .signWith(Keys.hmacShaKeyFor(SECRET.toByteArray())) + .compact() + } +}