Skip to content

Commit 57e962a

Browse files
blommishblommish
authored
Lagt til bibliotek LogFilter for MDC-håndtering og RequestTimeFilter (#3)
1 parent eca30c0 commit 57e962a

File tree

12 files changed

+319
-23
lines changed

12 files changed

+319
-23
lines changed

‎build.gradle.kts

+5
Original file line numberDiff line numberDiff line change
@@ -39,8 +39,13 @@ subprojects {
3939

4040
dependencies {
4141
implementation(platform("org.springframework.boot:spring-boot-dependencies:3.1.3"))
42+
4243
testImplementation("org.junit.jupiter:junit-jupiter")
4344
testImplementation("org.assertj:assertj-core")
45+
testImplementation("io.mockk:mockk:1.13.7")
46+
47+
testImplementation("ch.qos.logback:logback-core")
48+
testImplementation("ch.qos.logback:logback-classic")
4449
}
4550

4651
tasks.jar {

‎log/build.gradle.kts

+10
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,10 @@
1+
plugins {
2+
kotlin("plugin.spring") version "1.9.10"
3+
}
4+
5+
dependencies {
6+
implementation("org.springframework.boot:spring-boot")
7+
implementation("org.springframework:spring-web")
8+
implementation("org.slf4j:slf4j-api")
9+
implementation("jakarta.servlet:jakarta.servlet-api")
10+
}

‎log/src/main/kotlin/no/nav/tilleggsstonader/libs/log/IdUtils.kt

+10
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,10 @@
1+
package no.nav.tilleggsstonader.libs.log
2+
3+
import java.util.UUID
4+
5+
object IdUtils {
6+
fun generateId(): String {
7+
val uuid = UUID.randomUUID()
8+
return java.lang.Long.toHexString(uuid.mostSignificantBits) + java.lang.Long.toHexString(uuid.leastSignificantBits)
9+
}
10+
}

‎log/src/main/kotlin/no/nav/tilleggsstonader/libs/log/NavHttpHeaders.kt

+14
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
package no.nav.tilleggsstonader.libs.log
2+
3+
enum class NavHttpHeaders(private val header: String) {
4+
NAV_PERSONIDENT("Nav-Personident"),
5+
NAV_CALL_ID("Nav-Call-Id"),
6+
NGNINX_REQUEST_ID("X-Request-Id"),
7+
NAV_CONSUMER_ID("Nav-Consumer-Id"),
8+
NAV_USER_ID("Nav-User-Id"),
9+
;
10+
11+
fun asString(): String {
12+
return header
13+
}
14+
}

‎log/src/main/kotlin/no/nav/tilleggsstonader/libs/log/filter/LogFilter.kt

+120
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,120 @@
1+
package no.nav.tilleggsstonader.libs.log.filter
2+
3+
import jakarta.servlet.FilterChain
4+
import jakarta.servlet.http.Cookie
5+
import jakarta.servlet.http.HttpFilter
6+
import jakarta.servlet.http.HttpServletRequest
7+
import jakarta.servlet.http.HttpServletResponse
8+
import no.nav.tilleggsstonader.libs.log.IdUtils
9+
import no.nav.tilleggsstonader.libs.log.NavHttpHeaders
10+
import no.nav.tilleggsstonader.libs.log.mdc.MDCConstants.MDC_CALL_ID
11+
import no.nav.tilleggsstonader.libs.log.mdc.MDCConstants.MDC_CONSUMER_ID
12+
import no.nav.tilleggsstonader.libs.log.mdc.MDCConstants.MDC_REQUEST_ID
13+
import no.nav.tilleggsstonader.libs.log.mdc.MDCConstants.MDC_USER_ID
14+
import org.slf4j.LoggerFactory
15+
import org.slf4j.MDC
16+
import java.io.EOFException
17+
18+
class LogFilter : HttpFilter() {
19+
20+
override fun doFilter(
21+
request: HttpServletRequest,
22+
response: HttpServletResponse,
23+
filterChain: FilterChain,
24+
) {
25+
val userId = resolveUserId(request)
26+
if (userId.isNullOrEmpty()) {
27+
// user-id tracking only works if the client is stateful and supports cookies.
28+
// if no user-id is found, generate one for any following requests but do not use it on the
29+
// current request to avoid generating large numbers of useless user-ids.
30+
generateUserIdCookie(response)
31+
}
32+
val consumerId = request.getHeader(NavHttpHeaders.NAV_CONSUMER_ID.asString())
33+
val callId = resolveCallId(request)
34+
MDC.put(MDC_CALL_ID, callId)
35+
MDC.put(MDC_USER_ID, userId)
36+
MDC.put(MDC_CONSUMER_ID, consumerId)
37+
MDC.put(MDC_REQUEST_ID, resolveRequestId(request))
38+
response.setHeader(NavHttpHeaders.NAV_CALL_ID.asString(), callId)
39+
40+
try {
41+
filterWithErrorHandling(request, response, filterChain)
42+
} finally {
43+
MDC.remove(MDC_CALL_ID)
44+
MDC.remove(MDC_USER_ID)
45+
MDC.remove(MDC_CONSUMER_ID)
46+
MDC.remove(MDC_REQUEST_ID)
47+
}
48+
}
49+
50+
private fun filterWithErrorHandling(
51+
request: HttpServletRequest,
52+
response: HttpServletResponse,
53+
filterChain: FilterChain,
54+
) {
55+
try {
56+
filterChain.doFilter(request, response)
57+
} catch (e: Exception) {
58+
if (e is EOFException) {
59+
LOG.warn(e.message, e)
60+
} else {
61+
LOG.error(e.message, e)
62+
if (response.isCommitted) {
63+
LOG.error("failed with status={}", response.status)
64+
throw e
65+
}
66+
response.status = HttpServletResponse.SC_INTERNAL_SERVER_ERROR
67+
}
68+
}
69+
}
70+
71+
private fun resolveCallId(request: HttpServletRequest): String {
72+
return NAV_CALL_ID_HEADER_NAMES
73+
.mapNotNull { request.getHeader(it) }
74+
.firstOrNull { it.isNotEmpty() }
75+
?: IdUtils.generateId()
76+
}
77+
78+
private fun resolveRequestId(request: HttpServletRequest): String {
79+
return NAV_REQUEST_ID_HEADER_NAMES
80+
.mapNotNull { request.getHeader(it) }
81+
.firstOrNull { it.isNotEmpty() }
82+
?: IdUtils.generateId()
83+
}
84+
85+
private fun generateUserIdCookie(response: HttpServletResponse) {
86+
val userId = IdUtils.generateId()
87+
val cookie = Cookie(RANDOM_USER_ID_COOKIE_NAME, userId).apply {
88+
path = "/"
89+
maxAge = ONE_MONTH_IN_SECONDS
90+
isHttpOnly = true
91+
secure = true
92+
}
93+
response.addCookie(cookie)
94+
}
95+
96+
private fun resolveUserId(request: HttpServletRequest): String? {
97+
return request.cookies?.firstOrNull { it -> RANDOM_USER_ID_COOKIE_NAME == it.name }?.value
98+
}
99+
100+
companion object {
101+
// there is no consensus in NAV about header-names for correlation ids, so we support 'em all!
102+
// https://nav-it.slack.com/archives/C9UQ16AH4/p1538488785000100
103+
private val NAV_CALL_ID_HEADER_NAMES =
104+
listOf(
105+
NavHttpHeaders.NAV_CALL_ID.asString(),
106+
"Nav-CallId",
107+
"Nav-Callid",
108+
"X-Correlation-Id",
109+
)
110+
111+
private val NAV_REQUEST_ID_HEADER_NAMES =
112+
listOf(
113+
"X_Request_Id",
114+
"X-Request-Id",
115+
)
116+
private val LOG = LoggerFactory.getLogger(LogFilter::class.java)
117+
private const val RANDOM_USER_ID_COOKIE_NAME = "RUIDC"
118+
private const val ONE_MONTH_IN_SECONDS = 60 * 60 * 24 * 30
119+
}
120+
}

‎log/src/main/kotlin/no/nav/tilleggsstonader/libs/log/filter/LogFilterConfiguration.kt

+30
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,30 @@
1+
package no.nav.tilleggsstonader.libs.log.filter
2+
3+
import org.slf4j.LoggerFactory
4+
import org.springframework.boot.web.servlet.FilterRegistrationBean
5+
import org.springframework.context.annotation.Bean
6+
import org.springframework.context.annotation.Configuration
7+
8+
@Configuration
9+
class LogFilterConfiguration {
10+
11+
private val logger = LoggerFactory.getLogger(javaClass)
12+
13+
@Bean
14+
fun logFilter(): FilterRegistrationBean<LogFilter> {
15+
logger.info("Registering LogFilter filter")
16+
val filterRegistration = FilterRegistrationBean<LogFilter>()
17+
filterRegistration.filter = LogFilter()
18+
filterRegistration.order = 1
19+
return filterRegistration
20+
}
21+
22+
@Bean
23+
fun requestTimeFilter(): FilterRegistrationBean<RequestTimeFilter> {
24+
logger.info("Registering RequestTimeFilter filter")
25+
val filterRegistration = FilterRegistrationBean<RequestTimeFilter>()
26+
filterRegistration.filter = RequestTimeFilter()
27+
filterRegistration.order = 2
28+
return filterRegistration
29+
}
30+
}

‎log/src/main/kotlin/no/nav/tilleggsstonader/libs/log/filter/RequestTimeFilter.kt

+51
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,51 @@
1+
package no.nav.tilleggsstonader.libs.log.filter
2+
3+
import jakarta.servlet.FilterChain
4+
import jakarta.servlet.http.HttpFilter
5+
import jakarta.servlet.http.HttpServletRequest
6+
import jakarta.servlet.http.HttpServletResponse
7+
import org.slf4j.LoggerFactory
8+
import org.springframework.http.HttpStatus
9+
import org.springframework.util.StopWatch
10+
11+
class RequestTimeFilter : HttpFilter() {
12+
13+
override fun doFilter(
14+
request: HttpServletRequest,
15+
response: HttpServletResponse,
16+
filterChain: FilterChain,
17+
) {
18+
val timer = StopWatch()
19+
try {
20+
timer.start()
21+
filterChain.doFilter(request, response)
22+
} finally {
23+
timer.stop()
24+
log(request, response.status, timer)
25+
}
26+
}
27+
28+
private fun log(request: HttpServletRequest, code: Int, timer: StopWatch) {
29+
if (HttpStatus.valueOf(code).isError) {
30+
LOG.warn("{} - {} - ({}). Dette tok {}ms", request.method, request.requestURI, code, timer.totalTimeMillis)
31+
} else {
32+
if (!shouldNotFilter(request.requestURI)) {
33+
LOG.info(
34+
"{} - {} - ({}). Dette tok {}ms",
35+
request.method,
36+
request.requestURI,
37+
code,
38+
timer.totalTimeMillis,
39+
)
40+
}
41+
}
42+
}
43+
44+
private fun shouldNotFilter(uri: String): Boolean {
45+
return uri.contains("/internal") || uri == "/api/ping"
46+
}
47+
48+
companion object {
49+
private val LOG = LoggerFactory.getLogger(RequestTimeFilter::class.java)
50+
}
51+
}

‎log/src/main/kotlin/no/nav/tilleggsstonader/libs/log/mdc/MDCConstants.kt

+8
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,8 @@
1+
package no.nav.tilleggsstonader.libs.log.mdc
2+
3+
object MDCConstants {
4+
const val MDC_USER_ID = "userId"
5+
const val MDC_CONSUMER_ID = "consumerId"
6+
const val MDC_CALL_ID = "callId"
7+
const val MDC_REQUEST_ID = "requestId"
8+
}

‎log/src/test/kotlin/no/nav/tilleggsstonader/libs/log/filter/LogFilterTest.kt

+69
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,69 @@
1+
package no.nav.tilleggsstonader.libs.log.filter
2+
3+
import io.mockk.every
4+
import io.mockk.mockk
5+
import jakarta.servlet.http.HttpServletRequest
6+
import jakarta.servlet.http.HttpServletResponse
7+
import no.nav.tilleggsstonader.libs.log.NavHttpHeaders
8+
import org.assertj.core.api.Assertions.assertThat
9+
import org.junit.jupiter.api.BeforeEach
10+
import org.junit.jupiter.api.Test
11+
import org.slf4j.MDC
12+
13+
class LogFilterTest {
14+
15+
private lateinit var httpServletRequest: HttpServletRequest
16+
private lateinit var httpServletResponse: HttpServletResponse
17+
private val logFilter = LogFilter()
18+
19+
@BeforeEach
20+
fun setup() {
21+
httpServletRequest = mockHttpServletRequest
22+
httpServletResponse = mockHttpServletResponse
23+
}
24+
25+
@Test
26+
fun cleanupOfMDCContext() {
27+
val initialContextMap = MDC.getCopyOfContextMap() ?: HashMap()
28+
29+
logFilter.doFilter(
30+
httpServletRequest,
31+
httpServletResponse,
32+
) { _, _ -> }
33+
34+
assertThat(initialContextMap)
35+
.isEqualTo(MDC.getCopyOfContextMap() ?: HashMap<String, String>())
36+
}
37+
38+
@Test
39+
fun addResponseHeaders() {
40+
logFilter.doFilter(httpServletRequest, httpServletResponse) { _, _ -> }
41+
42+
assertThat(httpServletResponse.getHeader(NavHttpHeaders.NAV_CALL_ID.asString()))
43+
.isNotEmpty()
44+
assertThat(httpServletResponse.getHeader("Server")).isNull()
45+
}
46+
47+
@Test
48+
fun handleExceptions() {
49+
logFilter.doFilter(httpServletRequest, httpServletResponse) { _, _ -> throw IllegalStateException("") }
50+
51+
assertThat(httpServletResponse.status)
52+
.isEqualTo(HttpServletResponse.SC_INTERNAL_SERVER_ERROR)
53+
}
54+
55+
private val mockHttpServletRequest = mockk<HttpServletRequest>(relaxed = true).also {
56+
every { it.method } returns "GET"
57+
every { it.requestURI } returns "/test/path"
58+
}
59+
60+
private val mockHttpServletResponse = mockk<HttpServletResponse>(relaxed = true).also {
61+
val headers: MutableMap<String, String> = HashMap()
62+
val status = intArrayOf(0)
63+
every { it.status = any() } answers { status[0] = firstArg() }
64+
every { it.setHeader(any(), any()) } answers { headers[firstArg()] = secondArg() }
65+
every { it.status } answers { status[0] }
66+
every { it.getHeader(any()) } answers { headers[firstArg()] }
67+
every { it.headerNames } answers { headers.keys }
68+
}
69+
}

‎logs/src/main/kotlin/no/nav/tilleggsstonader/libs/logs/Library.kt

-10
This file was deleted.

‎logs/src/test/kotlin/no/nav/tilleggsstonader/libs/logs/LibraryTest.kt

-12
This file was deleted.

‎settings.gradle.kts

+2-1
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
rootProject.name = "tilleggsstonader-libs"
2-
include("logs")
32

43
plugins {
54
id("org.gradle.toolchains.foojay-resolver-convention") version "0.7.0"
65
}
6+
7+
include("log")

0 commit comments

Comments
 (0)