diff --git a/buildSrc/src/main/kotlin/conventions.gradle.kts b/buildSrc/src/main/kotlin/conventions.gradle.kts index 987b18c..886cd5c 100644 --- a/buildSrc/src/main/kotlin/conventions.gradle.kts +++ b/buildSrc/src/main/kotlin/conventions.gradle.kts @@ -1,4 +1,3 @@ -import org.jetbrains.kotlin.gradle.dsl.JvmTarget import org.jlleitschuh.gradle.ktlint.KtlintExtension plugins { @@ -23,14 +22,10 @@ repositories { } kotlin { - compilerOptions { - jvmTarget = JvmTarget.JVM_17 - } - jvmToolchain(21) + jvmToolchain(17) } java { - targetCompatibility = JavaVersion.VERSION_17 withSourcesJar() } diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 3a2331f..3a5c101 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -4,6 +4,7 @@ jreleaser = "1.18.0" junit = "5.12.2" kotest = "5.9.1" kotlin = "2.1.20" +kotlinxCoroutines = "1.10.2" ktlint = "12.2.0" logbackAccess = "2.0.6" logbackClassic = "1.5.18" @@ -18,6 +19,8 @@ junit-jupiter = { group = "org.junit.jupiter", name = "junit-jupiter", version.r junit-platformLauncher = { group = "org.junit.platform", name = "junit-platform-launcher" } kotest-assertions-core-jvm = { group = "io.kotest", name = "kotest-assertions-core-jvm", version.ref = "kotest" } kotlin-gradlePlugin = { group = "org.jetbrains.kotlin", name = "kotlin-gradle-plugin", version.ref = "kotlin" } +kotlinx-coroutines-core = { group = "org.jetbrains.kotlinx", name = "kotlinx-coroutines-core", version.ref = "kotlinxCoroutines" } +kotlinx-coroutines-reactor = { group = "org.jetbrains.kotlinx", name = "kotlinx-coroutines-reactor", version.ref = "kotlinxCoroutines" } ktlintPlugin = { group = "org.jlleitschuh.gradle.ktlint", name = "org.jlleitschuh.gradle.ktlint.gradle.plugin", version.ref = "ktlint" } logback-access-common = { group = "ch.qos.logback.access", name = "logback-access-common", version.ref = "logbackAccess" } logback-classic = { group = "ch.qos.logback", name = "logback-classic", version.ref = "logbackClassic" } diff --git a/logback-access-reactor-netty/build.gradle.kts b/logback-access-reactor-netty/build.gradle.kts index ff2bd36..f3a73e3 100644 --- a/logback-access-reactor-netty/build.gradle.kts +++ b/logback-access-reactor-netty/build.gradle.kts @@ -11,6 +11,8 @@ dependencies { testImplementation(libs.junit.jupiter) testImplementation(libs.kotest.assertions.core.jvm) + testImplementation(libs.kotlinx.coroutines.core) + testImplementation(libs.kotlinx.coroutines.reactor) testImplementation(libs.logback.classic) testImplementation(libs.logback.core) testImplementation(libs.mockk) diff --git a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEvent.kt b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEvent.kt index 014913c..ba7efd5 100644 --- a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEvent.kt +++ b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEvent.kt @@ -2,6 +2,9 @@ package io.github.dmitrysulman.logback.access.reactor.netty import ch.qos.logback.access.common.spi.AccessContext import ch.qos.logback.access.common.spi.IAccessEvent +import jakarta.servlet.http.Cookie +import jakarta.servlet.http.HttpServletRequest +import jakarta.servlet.http.HttpServletResponse import reactor.netty.http.server.logging.AccessLogArgProvider import java.io.Serializable import java.net.InetSocketAddress @@ -37,7 +40,7 @@ class AccessEvent( private val _sequenceNumber = context.sequenceNumberGenerator?.nextSequenceNumber() ?: 0 private val _elapsedTime = argProvider.duration() private val _elapsedTimeSeconds = _elapsedTime / 1000 - private val _requestUri by lazy { argProvider.uri()?.toString()?.substringBefore("?") ?: NA } + private val _requestPath by lazy { argProvider.uri()?.toString()?.substringBefore("?") ?: NA } private val _queryString by lazy { argProvider.uri()?.let { uri -> uri @@ -47,6 +50,7 @@ class AccessEvent( .orEmpty() } ?: NA } + private val _requestUrl by lazy { "$_method ${argProvider.uri()?.toString() ?: NA} $_protocol" } private val _remoteHost by lazy { val remoteAddress = argProvider.connectionInformation()?.connectionRemoteAddress() if (remoteAddress is InetSocketAddress) { @@ -58,22 +62,19 @@ class AccessEvent( private val _remoteUser by lazy { argProvider.user() ?: NA } private val _protocol by lazy { argProvider.protocol() ?: NA } private val _method by lazy { argProvider.method()?.toString() ?: NA } - private lateinit var _threadName: String + private var _threadName: String? = null private val _requestParameterMap by lazy { _queryString - .takeIf { it.isNotEmpty() && it != NA } + .takeIf { it.length > 1 } ?.substring(1) ?.split("&") + ?.asSequence() ?.mapNotNull { val index = it.indexOf("=") - if (index in 1..it.length - 2) { - it.substring(0, index) to it.substring(index + 1) - } else { - null - } - }?.groupBy({ URLDecoder.decode(it.first, StandardCharsets.UTF_8) }) { - URLDecoder.decode(it.second, StandardCharsets.UTF_8) - }?.mapValues { it.value.toTypedArray() } + if (index !in 1..it.length - 2) return@mapNotNull null + it.substring(0, index) to it.substring(index + 1) + }?.groupBy({ it.first.decodeCatching() }) { it.second.decodeCatching() } + ?.mapValues { it.value.toTypedArray() } ?: emptyMap() } private val _remoteAddr by lazy { @@ -85,9 +86,27 @@ class AccessEvent( } ?: NA } private val _cookieMap by lazy { - argProvider.cookies()?.entries?.associate { - it.key.toString() to (it.value.firstOrNull()?.value() ?: NA) - } ?: emptyMap() + argProvider + .cookies() + ?.asSequence() + ?.mapNotNull { (name, values) -> + if (name.isNullOrBlank()) return@mapNotNull null + val value = values.firstOrNull()?.value() ?: return@mapNotNull null + name.toString() to value + }?.toMap() ?: emptyMap() + } + private val _cookieList by lazy { + argProvider + .cookies() + ?.mapNotNull { (name, values) -> + if (name.isNullOrBlank()) return@mapNotNull null + val value = values.firstOrNull()?.value() ?: return@mapNotNull null + try { + Cookie(name.toString(), value) + } catch (_: Exception) { + null + } + } ?: emptyList() } private val _contentLength by lazy { _serverAdapter.contentLength } private val _statusCode by lazy { _serverAdapter.statusCode } @@ -97,15 +116,26 @@ class AccessEvent( argProvider .requestHeaderIterator() ?.asSequence() - ?.associate { it.key.toString() to it.value.toString() } + ?.mapNotNull { (name, value) -> + if (name.isNullOrEmpty()) return@mapNotNull null + if (value == null) return@mapNotNull null + name.toString() to value.toString() + }?.toMap() ?: emptyMap() } - @Transient - private val _serverAdapter = ReactorNettyServerAdapter(argProvider) + private val _serverAdapter by lazy { ReactorNettyServerAdapter(argProvider) } + + private fun String.decodeCatching() = + try { + URLDecoder.decode(this, StandardCharsets.UTF_8) + } catch (_: Exception) { + this + } override fun prepareForDeferredProcessing() { requestURI + requestURL queryString remoteHost remoteUser @@ -114,16 +144,19 @@ class AccessEvent( requestParameterMap remoteAddr getCookieMap() + cookies contentLength statusCode localPort responseHeaderMap requestHeaderMap + threadName + serverAdapter.requestTimestamp } - override fun getRequest() = null + override fun getRequest(): HttpServletRequest? = null - override fun getResponse() = null + override fun getResponse(): HttpServletResponse? = null override fun getTimeStamp() = _timeStamp @@ -133,9 +166,9 @@ class AccessEvent( override fun getElapsedSeconds() = _elapsedTimeSeconds - override fun getRequestURI() = _requestUri + override fun getRequestURI() = _requestPath - override fun getRequestURL() = "$_method $_requestUri$_queryString $_protocol" + override fun getRequestURL() = _requestUrl override fun getRemoteHost() = _remoteHost @@ -171,6 +204,8 @@ class AccessEvent( override fun getRequestParameter(key: String) = _requestParameterMap[key] ?: NA_ARRAY + override fun getCookies() = _cookieList + private fun getCookieMap() = _cookieMap override fun getCookie(key: String) = getCookieMap()[key] ?: NA @@ -189,7 +224,7 @@ class AccessEvent( override fun getResponseHeader(key: String) = _responseHeaderMap[key] ?: NA - override fun getResponseHeaderMap(): Map = _responseHeaderMap + override fun getResponseHeaderMap() = _responseHeaderMap override fun getResponseHeaderNameList() = _responseHeaderMap.keys.toList() diff --git a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLog.kt b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLog.kt index 8fbb00d..8697acc 100644 --- a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLog.kt +++ b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLog.kt @@ -41,7 +41,7 @@ class AccessLog( public override fun log() { try { val accessEvent = AccessEvent(argProvider, accessContext) - accessEvent.threadName = Thread.currentThread().name + accessEvent.setThreadName(Thread.currentThread().name) if (accessContext.getFilterChainDecision(accessEvent) != FilterReply.DENY) { accessContext.callAppenders(accessEvent) } diff --git a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/Extensions.kt b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/Extensions.kt new file mode 100644 index 0000000..02e835e --- /dev/null +++ b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/Extensions.kt @@ -0,0 +1,11 @@ +package io.github.dmitrysulman.logback.access.reactor.netty + +import reactor.netty.http.server.HttpServer + +/** + * Extension for [HttpServer] providing [HttpServer.accessLog] method alternative. + * + * @param reactorNettyAccessLogFactory The [ReactorNettyAccessLogFactory] instance for access log configuration. + */ +fun HttpServer.enableLogbackAccess(reactorNettyAccessLogFactory: ReactorNettyAccessLogFactory): HttpServer = + accessLog(true, reactorNettyAccessLogFactory) diff --git a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapter.kt b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapter.kt index ec25794..36e0154 100644 --- a/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapter.kt +++ b/logback-access-reactor-netty/src/main/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapter.kt @@ -2,20 +2,33 @@ package io.github.dmitrysulman.logback.access.reactor.netty import ch.qos.logback.access.common.spi.ServerAdapter import reactor.netty.http.server.logging.AccessLogArgProvider +import java.io.Serializable class ReactorNettyServerAdapter( + @Transient private val argProvider: AccessLogArgProvider, -) : ServerAdapter { - override fun getRequestTimestamp() = argProvider.accessDateTime()?.toInstant()?.toEpochMilli() ?: 0 - - override fun getContentLength() = argProvider.contentLength() - - override fun getStatusCode() = argProvider.status()?.toString()?.toIntOrNull() ?: -1 - - override fun buildResponseHeaderMap() = +) : ServerAdapter, + Serializable { + private val _requestTimestamp by lazy { argProvider.accessDateTime()?.toInstant()?.toEpochMilli() ?: 0 } + private val _contentLength by lazy { argProvider.contentLength() } + private val _statusCode by lazy { argProvider.status()?.toString()?.toIntOrNull() ?: -1 } + private val _responseHeaderMap by lazy { argProvider .responseHeaderIterator() ?.asSequence() - ?.associate { it.key.toString() to it.value.toString() } + ?.mapNotNull { (name, value) -> + if (name.isNullOrEmpty()) return@mapNotNull null + if (value == null) return@mapNotNull null + name.toString() to value.toString() + }?.toMap() ?: emptyMap() + } + + override fun getRequestTimestamp() = _requestTimestamp + + override fun getContentLength() = _contentLength + + override fun getStatusCode() = _statusCode + + override fun buildResponseHeaderMap() = _responseHeaderMap } diff --git a/logback-access-reactor-netty/src/test/java/io/github/dmitrysulman/logback/access/reactor/netty/integration/JavaIntegrationTests.java b/logback-access-reactor-netty/src/test/java/io/github/dmitrysulman/logback/access/reactor/netty/integration/JavaIntegrationTests.java new file mode 100644 index 0000000..64f3b03 --- /dev/null +++ b/logback-access-reactor-netty/src/test/java/io/github/dmitrysulman/logback/access/reactor/netty/integration/JavaIntegrationTests.java @@ -0,0 +1,46 @@ +package io.github.dmitrysulman.logback.access.reactor.netty.integration; + +import ch.qos.logback.access.common.joran.JoranConfigurator; +import io.github.dmitrysulman.logback.access.reactor.netty.ReactorNettyAccessLogFactory; +import org.junit.jupiter.api.Test; +import reactor.core.publisher.Mono; +import reactor.netty.http.client.HttpClient; +import reactor.netty.http.server.HttpServer; + +import java.time.Duration; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; + +public class JavaIntegrationTests { + @Test + public void smokeTest() throws InterruptedException { + var accessLogFactory = + new ReactorNettyAccessLogFactory("logback-access-stdout.xml", new JoranConfigurator(), true); + var eventCaptureAppender = (EventCaptureAppender) accessLogFactory.getAccessContext().getAppender("CAPTURE"); + var responseBody = "test"; + var server = HttpServer + .create() + .accessLog(true, accessLogFactory) + .handle((request, response) -> response.sendByteArray(Mono.just(responseBody.getBytes()))) + .bindNow(); + var uri = "/test"; + var response = HttpClient + .create() + .port(server.port()) + .get() + .uri(uri) + .response() + .block(Duration.ofSeconds(10)); + + assertNotNull(response); + assertEquals(200, response.status().code()); + + Thread.sleep(100); + assertEquals(1, eventCaptureAppender.getList().size()); + assertEquals(uri, eventCaptureAppender.getList().get(0).getRequestURI()); + assertEquals(responseBody.length(), eventCaptureAppender.getList().get(0).getContentLength()); + + server.disposeNow(); + } +} diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEventTests.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEventTests.kt index 944987e..8edf39f 100644 --- a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEventTests.kt +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessEventTests.kt @@ -1,65 +1,46 @@ package io.github.dmitrysulman.logback.access.reactor.netty import ch.qos.logback.access.common.spi.AccessContext +import io.kotest.matchers.booleans.shouldBeFalse +import io.kotest.matchers.collections.shouldBeEmpty +import io.kotest.matchers.collections.shouldContain +import io.kotest.matchers.longs.shouldBeZero +import io.kotest.matchers.maps.shouldBeEmpty import io.kotest.matchers.maps.shouldContainKey +import io.kotest.matchers.nulls.shouldBeNull +import io.kotest.matchers.nulls.shouldNotBeNull import io.kotest.matchers.shouldBe +import io.kotest.matchers.string.shouldBeEmpty import io.mockk.every import io.mockk.mockk import io.mockk.verify +import io.netty.handler.codec.http.cookie.DefaultCookie +import jakarta.servlet.http.Cookie import org.junit.jupiter.api.Test import reactor.netty.http.server.ConnectionInformation import reactor.netty.http.server.logging.AccessLogArgProvider +import java.io.ByteArrayInputStream +import java.io.ByteArrayOutputStream +import java.io.ObjectInputStream +import java.io.ObjectOutputStream import java.net.SocketAddress +import java.time.Instant +import java.time.ZoneId +import java.time.ZonedDateTime import java.util.Collections +import io.netty.handler.codec.http.cookie.Cookie as NettyCookie -// TODO serialization of AccessEvent -// TODO cookies -// TODO request/response headers class AccessEventTests { @Test fun `test basic properties`() { val mockContext = mockk(relaxed = true) - val mockConnectionInformation = mockk() - every { mockConnectionInformation.connectionRemoteAddress() } returns - object : SocketAddress() { - override fun toString() = "192.168.1.1" - } - every { mockConnectionInformation.hostPort() } returns 1000 val mockArgProvider = mockk() - every { mockArgProvider.method() } returns "GET" - every { mockArgProvider.uri() } returns "/test?param=value" - every { mockArgProvider.protocol() } returns "HTTP/1.1" - every { mockArgProvider.status() } returns "200" - every { mockArgProvider.contentLength() } returns 100 - every { mockArgProvider.duration() } returns 1001 - every { mockArgProvider.user() } returns "username" - every { mockArgProvider.requestHeaderIterator() } returns Collections.emptyIterator() - every { mockArgProvider.responseHeaderIterator() } returns Collections.emptyIterator() - every { mockArgProvider.cookies() } returns emptyMap() - every { mockArgProvider.connectionInformation() } returns mockConnectionInformation + mockArgProvider(mockArgProvider) val accessEvent = AccessEvent(mockArgProvider, mockContext) + accessEvent.setThreadName(THREAD) - accessEvent.method shouldBe "GET" - accessEvent.requestURI shouldBe "/test" - accessEvent.queryString shouldBe "?param=value" - accessEvent.getRequestParameter("param") shouldBe arrayOf("value") - accessEvent.getRequestParameter("no_param") shouldBe NA_ARRAY - accessEvent.protocol shouldBe "HTTP/1.1" - accessEvent.requestURL shouldBe "GET /test?param=value HTTP/1.1" - accessEvent.statusCode shouldBe 200 - accessEvent.contentLength shouldBe 100L - accessEvent.elapsedTime shouldBe 1001L - accessEvent.elapsedSeconds shouldBe 1L - accessEvent.remoteAddr shouldBe "192.168.1.1" - accessEvent.remoteHost shouldBe "192.168.1.1" - accessEvent.serverName shouldBe "192.168.1.1" - accessEvent.localPort shouldBe 1000 - accessEvent.remoteUser shouldBe "username" - accessEvent.sequenceNumber shouldBe 0 - accessEvent.getRequestHeader("Header") shouldBe NA - accessEvent.getResponseHeader("Header") shouldBe NA - accessEvent.getCookie("cookie") shouldBe NA + assertAllMethods(accessEvent) } @Test @@ -91,7 +72,7 @@ class AccessEventTests { accessEvent.requestURI accessEvent.queryString accessEvent.requestParameterMap - accessEvent.getRequestParameter("param") + accessEvent.getRequestParameter(PARAM) accessEvent.protocol accessEvent.requestURL accessEvent.statusCode @@ -103,13 +84,14 @@ class AccessEventTests { accessEvent.serverName accessEvent.localPort accessEvent.remoteUser - accessEvent.getRequestHeader("Header") - accessEvent.getResponseHeader("Header") + accessEvent.getRequestHeader(HEADER) + accessEvent.getResponseHeader(HEADER) accessEvent.requestHeaderMap accessEvent.requestHeaderNames accessEvent.responseHeaderMap accessEvent.responseHeaderNameList - accessEvent.getCookie("cookie") + accessEvent.cookies + accessEvent.getCookie(COOKIE) } verifyAllMethods(mockArgProvider, mockConnectionInformation) @@ -136,14 +118,14 @@ class AccessEventTests { mockConnectionInformation: ConnectionInformation, ) { verify(exactly = 1) { mockArgProvider.method() } - verify(exactly = 2) { mockArgProvider.uri() } + verify(exactly = 3) { mockArgProvider.uri() } verify(exactly = 1) { mockArgProvider.protocol() } verify(exactly = 1) { mockArgProvider.status() } verify(exactly = 1) { mockArgProvider.contentLength() } verify(exactly = 1) { mockArgProvider.user() } verify(exactly = 1) { mockArgProvider.requestHeaderIterator() } verify(exactly = 1) { mockArgProvider.responseHeaderIterator() } - verify(exactly = 1) { mockArgProvider.cookies() } + verify(exactly = 2) { mockArgProvider.cookies() } verify(exactly = 3) { mockArgProvider.connectionInformation() } verify(exactly = 2) { mockConnectionInformation.connectionRemoteAddress() } verify(exactly = 1) { mockConnectionInformation.hostPort() } @@ -153,26 +135,53 @@ class AccessEventTests { fun `test request URL with no query parameters`() { val mockContext = mockk(relaxed = true) val mockArgProvider = mockk(relaxed = true) - every { mockArgProvider.method() } returns "GET" - every { mockArgProvider.uri() } returns "/test" - every { mockArgProvider.protocol() } returns "HTTP/1.1" + every { mockArgProvider.method() } returns GET + every { mockArgProvider.uri() } returns REQUEST_URI + every { mockArgProvider.protocol() } returns HTTP11 val accessEvent = AccessEvent(mockArgProvider, mockContext) accessEvent.requestURL shouldBe "GET /test HTTP/1.1" } + @Test + fun `test empty request URI`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk(relaxed = true) + every { mockArgProvider.uri() } returns "" + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.requestURI.shouldBeEmpty() + accessEvent.queryString.shouldBeEmpty() + accessEvent.requestParameterMap.shouldBeEmpty() + accessEvent.getRequestParameter(PARAM) shouldBe NA_ARRAY + } + + @Test + fun `test query string parsing - question mark without parameters`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk(relaxed = true) + every { mockArgProvider.uri() } returns "/test?" + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.queryString shouldBe "?" + accessEvent.requestParameterMap.shouldBeEmpty() + accessEvent.getRequestParameter(PARAM) shouldBe NA_ARRAY + } + @Test fun `test query string parsing - no parameters`() { val mockContext = mockk(relaxed = true) val mockArgProvider = mockk(relaxed = true) - every { mockArgProvider.uri() } returns "/test" + every { mockArgProvider.uri() } returns REQUEST_URI val accessEvent = AccessEvent(mockArgProvider, mockContext) - accessEvent.queryString.isEmpty() shouldBe true - accessEvent.requestParameterMap.isEmpty() shouldBe true - accessEvent.getRequestParameter("param") shouldBe NA_ARRAY + accessEvent.queryString.shouldBeEmpty() + accessEvent.requestParameterMap.shouldBeEmpty() + accessEvent.getRequestParameter(PARAM) shouldBe NA_ARRAY } @Test @@ -228,60 +237,306 @@ class AccessEventTests { val accessEvent = AccessEvent(mockArgProvider, mockContext) accessEvent.queryString shouldBe "?param1=" - accessEvent.requestParameterMap.isEmpty() shouldBe true + accessEvent.requestParameterMap.shouldBeEmpty() accessEvent.getRequestParameter("param1") shouldBe NA_ARRAY } @Test - fun `test query string parsing - URL encoded parameters`() { + fun `test query string parsing - URL encoded parameters with special characters`() { val mockContext = mockk(relaxed = true) val mockArgProvider = mockk(relaxed = true) - every { mockArgProvider.uri() } returns "/test?param%201=value%201¶m2=value+2" + every { mockArgProvider.uri() } returns + "/test?param%201=value+1¶m2=v%20a%2Bl%26u%3De%24%23%28%29%40%21123%C2%B1%2F%5C%3C%3E%2C%22%3B%27%25%3F" val accessEvent = AccessEvent(mockArgProvider, mockContext) - accessEvent.queryString shouldBe "?param%201=value%201¶m2=value+2" + accessEvent.queryString shouldBe + "?param%201=value+1¶m2=v%20a%2Bl%26u%3De%24%23%28%29%40%21123%C2%B1%2F%5C%3C%3E%2C%22%3B%27%25%3F" accessEvent.requestParameterMap.size shouldBe 2 accessEvent.requestParameterMap shouldContainKey "param 1" accessEvent.requestParameterMap shouldContainKey "param2" accessEvent.getRequestParameter("param 1") shouldBe arrayOf("value 1") - accessEvent.getRequestParameter("param2") shouldBe arrayOf("value 2") + accessEvent.getRequestParameter("param2") shouldBe arrayOf("v a+l&u=e\$#()@!123±/\\<>,\";'%?") } @Test - fun `test query string parsing - special characters`() { + fun `test query string parsing - malformed URL encoding`() { val mockContext = mockk(relaxed = true) val mockArgProvider = mockk(relaxed = true) - every { mockArgProvider.uri() } returns "/test?param1=value%40%23%24¶m2=%26%3D%3F" + every { mockArgProvider.uri() } returns "/test?param1=%26%3D%3F¶m2=%Q6%3D%3F" val accessEvent = AccessEvent(mockArgProvider, mockContext) - accessEvent.queryString shouldBe "?param1=value%40%23%24¶m2=%26%3D%3F" + accessEvent.queryString shouldBe "?param1=%26%3D%3F¶m2=%Q6%3D%3F" accessEvent.requestParameterMap.size shouldBe 2 accessEvent.requestParameterMap shouldContainKey "param1" accessEvent.requestParameterMap shouldContainKey "param2" - accessEvent.getRequestParameter("param1") shouldBe arrayOf("value@#$") - accessEvent.getRequestParameter("param2") shouldBe arrayOf("&=?") + accessEvent.getRequestParameter("param1") shouldBe arrayOf("&=?") + accessEvent.getRequestParameter("param2") shouldBe arrayOf("%Q6%3D%3F") } @Test fun `test query string parsing - malformed query string`() { val mockContext = mockk(relaxed = true) val mockArgProvider = mockk(relaxed = true) - every { mockArgProvider.uri() } returns "/test?param1¶m2=value2&=value3¶m4=" + every { mockArgProvider.uri() } returns "/test?param1¶m2=value2&=value3¶m4=&&=¶m5&=&==&=param6=?" val accessEvent = AccessEvent(mockArgProvider, mockContext) - accessEvent.queryString shouldBe "?param1¶m2=value2&=value3¶m4=" + accessEvent.queryString shouldBe "?param1¶m2=value2&=value3¶m4=&&=¶m5&=&==&=param6=?" accessEvent.requestParameterMap.size shouldBe 1 accessEvent.requestParameterMap shouldContainKey "param2" accessEvent.getRequestParameter("param1") shouldBe NA_ARRAY accessEvent.getRequestParameter("param2") shouldBe arrayOf("value2") accessEvent.getRequestParameter("param4") shouldBe NA_ARRAY + accessEvent.getRequestParameter("param5") shouldBe NA_ARRAY + accessEvent.getRequestParameter("param6") shouldBe NA_ARRAY + } + + @Test + fun `test on null values`() { + val mockContext = mockk(relaxed = true) + val mockConnectionInformation = mockk() + every { mockConnectionInformation.connectionRemoteAddress() } returns null + val mockArgProvider = mockk() + every { mockArgProvider.duration() } returns 0 + every { mockArgProvider.method() } returns null + every { mockArgProvider.uri() } returns null + every { mockArgProvider.protocol() } returns null + every { mockArgProvider.status() } returns null + every { mockArgProvider.user() } returns null + every { mockArgProvider.requestHeaderIterator() } returns null + every { mockArgProvider.responseHeaderIterator() } returns null + every { mockArgProvider.cookies() } returns null + every { mockArgProvider.connectionInformation() } returns mockConnectionInformation + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.method shouldBe NA + accessEvent.requestURI shouldBe NA + accessEvent.queryString shouldBe NA + accessEvent.getRequestParameter(PARAM) shouldBe NA_ARRAY + accessEvent.protocol shouldBe NA + accessEvent.requestURL shouldBe "$NA $NA $NA" + accessEvent.statusCode shouldBe -1 + accessEvent.remoteAddr shouldBe NA + accessEvent.remoteHost shouldBe NA + accessEvent.serverName shouldBe NA + accessEvent.remoteUser shouldBe NA + accessEvent.getRequestHeader(HEADER) shouldBe NA + accessEvent.getResponseHeader(HEADER) shouldBe NA + accessEvent.requestHeaderMap.shouldBeEmpty() + accessEvent.requestHeaderNames.hasMoreElements().shouldBeFalse() + accessEvent.responseHeaderMap.shouldBeEmpty() + accessEvent.responseHeaderNameList.shouldBeEmpty() + accessEvent.cookies.shouldBeEmpty() + accessEvent.getCookie(COOKIE) shouldBe NA + } + + @Test + fun `test on null connectionInformation`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk() + every { mockArgProvider.duration() } returns 0 + every { mockArgProvider.connectionInformation() } returns null + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.remoteAddr shouldBe NA + accessEvent.remoteHost shouldBe NA + accessEvent.localPort shouldBe -1 + } + + @Test + fun `test cookies`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk(relaxed = true) + every { mockArgProvider.cookies() } returns + mapOf( + "cookie1" to setOf(DefaultCookie("cookie1", "value1")), + "cookie2" to + LinkedHashSet().apply { + add(DefaultCookie("cookie2", "value21")) + add(DefaultCookie("cookie2", "value22")) + }, + "cookie3" to emptySet(), + ) + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.cookies.size shouldBe 2 + accessEvent.cookies shouldContain Cookie("cookie1", "value1") + accessEvent.cookies shouldContain Cookie("cookie2", "value21") + accessEvent.getCookie("cookie1") shouldBe "value1" + accessEvent.getCookie("cookie2") shouldBe "value21" + accessEvent.getCookie("cookie3") shouldBe NA + accessEvent.getCookie("not_exist") shouldBe NA + } + + @Test + fun `should not throw on null or blank cookie name`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk(relaxed = true) + every { mockArgProvider.cookies() } returns + mapOf( + null to setOf(DefaultCookie(COOKIE, VALUE)), + "" to setOf(DefaultCookie(COOKIE, VALUE)), + " " to setOf(DefaultCookie(COOKIE, VALUE)), + "cookie1" to setOf(DefaultCookie("cookie1", "value1")), + ) + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.cookies.size shouldBe 1 + accessEvent.cookies shouldContain Cookie("cookie1", "value1") + accessEvent.getCookie("cookie1") shouldBe "value1" + accessEvent.getCookie("") shouldBe NA + accessEvent.getCookie(" ") shouldBe NA + } + + @Test + fun `test request headers`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk(relaxed = true) + every { mockArgProvider.requestHeaderIterator() } returns headerListIterator() + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.requestHeaderMap shouldBe + mapOf( + "name1" to "value1", + "name2" to "value2", + "empty_value" to "", + ) + accessEvent.requestHeaderNames + .asIterator() + .asSequence() + .toList() shouldBe + listOf("name1", "name2", "empty_value") + } + + @Test + fun `test response headers`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk(relaxed = true) + every { mockArgProvider.responseHeaderIterator() } returns headerListIterator() + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + + accessEvent.responseHeaderMap shouldBe + mapOf( + "name1" to "value1", + "name2" to "value2", + "empty_value" to "", + ) + accessEvent.responseHeaderNameList shouldBe + listOf("name1", "name2", "empty_value") + } + + @Test + fun `test serialization`() { + val mockContext = mockk(relaxed = true) + val mockArgProvider = mockk() + mockArgProvider(mockArgProvider) + + val accessEvent = AccessEvent(mockArgProvider, mockContext) + accessEvent.setThreadName(THREAD) + accessEvent.prepareForDeferredProcessing() + + val byteArrayOutputStream = ByteArrayOutputStream() + val objectOutputStream = ObjectOutputStream(byteArrayOutputStream) + objectOutputStream.writeObject(accessEvent) + objectOutputStream.flush() + objectOutputStream.close() + val byteArrayInputStream = ByteArrayInputStream(byteArrayOutputStream.toByteArray()) + val objectInputStream = ObjectInputStream(byteArrayInputStream) + val deserializedAccessEvent = objectInputStream.readObject() as AccessEvent + + assertAllMethods(deserializedAccessEvent) + } + + private fun assertAllMethods(accessEvent: AccessEvent) { + accessEvent.method shouldBe GET + accessEvent.requestURI shouldBe REQUEST_URI + accessEvent.queryString shouldBe QUERY_STRING + accessEvent.requestParameterMap.size shouldBe 1 + accessEvent.getRequestParameter(PARAM) shouldBe arrayOf(VALUE) + accessEvent.getRequestParameter("no_param") shouldBe NA_ARRAY + accessEvent.protocol shouldBe HTTP11 + accessEvent.requestURL shouldBe "$GET $REQUEST_URI$QUERY_STRING $HTTP11" + accessEvent.statusCode shouldBe OK_STATUS_CODE.toInt() + accessEvent.contentLength shouldBe CONTENT_LENGTH + accessEvent.elapsedTime shouldBe DURATION + accessEvent.elapsedSeconds shouldBe DURATION_SECONDS + accessEvent.remoteAddr shouldBe IP_ADDRESS + accessEvent.remoteHost shouldBe IP_ADDRESS + accessEvent.serverName shouldBe IP_ADDRESS + accessEvent.localPort shouldBe PORT + accessEvent.remoteUser shouldBe USERNAME + accessEvent.sequenceNumber.shouldBeZero() + accessEvent.getRequestHeader(HEADER) shouldBe NA + accessEvent.getResponseHeader(HEADER) shouldBe NA + accessEvent.requestHeaderMap.shouldBeEmpty() + accessEvent.requestHeaderNames.hasMoreElements().shouldBeFalse() + accessEvent.responseHeaderMap.shouldBeEmpty() + accessEvent.responseHeaderNameList.shouldBeEmpty() + accessEvent.cookies.shouldBeEmpty() + accessEvent.getCookie(COOKIE) shouldBe NA + accessEvent.threadName shouldBe THREAD + accessEvent.request.shouldBeNull() + accessEvent.response.shouldBeNull() + accessEvent.sessionID shouldBe NA + accessEvent.getAttribute(ATTRIBUTE) shouldBe NA + accessEvent.requestContent.shouldBeEmpty() + accessEvent.responseContent.shouldBeEmpty() + accessEvent.serverAdapter.shouldNotBeNull() + accessEvent.serverAdapter.requestTimestamp shouldBe TIMESTAMP + accessEvent.serverAdapter.contentLength shouldBe CONTENT_LENGTH + accessEvent.serverAdapter.statusCode shouldBe OK_STATUS_CODE.toInt() + accessEvent.serverAdapter.buildResponseHeaderMap().shouldBeEmpty() + } + + private fun mockArgProvider(mockArgProvider: AccessLogArgProvider) { + val mockConnectionInformation = mockk() + every { mockConnectionInformation.connectionRemoteAddress() } returns + object : SocketAddress() { + override fun toString() = IP_ADDRESS + } + every { mockConnectionInformation.hostPort() } returns PORT + every { mockArgProvider.method() } returns GET + every { mockArgProvider.uri() } returns "$REQUEST_URI$QUERY_STRING" + every { mockArgProvider.protocol() } returns HTTP11 + every { mockArgProvider.status() } returns OK_STATUS_CODE + every { mockArgProvider.contentLength() } returns CONTENT_LENGTH + every { mockArgProvider.duration() } returns DURATION + every { mockArgProvider.user() } returns USERNAME + every { mockArgProvider.accessDateTime() } returns ZonedDateTime.ofInstant(Instant.ofEpochMilli(TIMESTAMP), ZoneId.of("UTC")) + every { mockArgProvider.requestHeaderIterator() } returns Collections.emptyIterator() + every { mockArgProvider.responseHeaderIterator() } returns Collections.emptyIterator() + every { mockArgProvider.cookies() } returns emptyMap() + every { mockArgProvider.connectionInformation() } returns mockConnectionInformation } companion object { private const val NA = "-" private val NA_ARRAY = arrayOf(NA) + private const val GET = "GET" + private const val HTTP11 = "HTTP/1.1" + private const val OK_STATUS_CODE = "200" + private const val IP_ADDRESS = "192.168.1.1" + private const val USERNAME = "username" + private const val PORT = 1000 + private const val CONTENT_LENGTH = 100L + private const val DURATION = 1001L + private const val HEADER = "Header" + private const val COOKIE = "cookie" + private const val THREAD = "thread" + private const val ATTRIBUTE = "attribute" + private const val PARAM = "param" + private const val VALUE = "value" + private const val REQUEST_URI = "/test" + private const val QUERY_STRING = "?param=value" + private const val DURATION_SECONDS = 1L + private const val TIMESTAMP = 1746734856000 } } diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLogTests.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLogTests.kt index 70771cb..0cd134d 100644 --- a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLogTests.kt +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/AccessLogTests.kt @@ -2,7 +2,7 @@ package io.github.dmitrysulman.logback.access.reactor.netty import ch.qos.logback.access.common.spi.AccessContext import ch.qos.logback.core.spi.FilterReply -import ch.qos.logback.core.status.Status +import ch.qos.logback.core.status.ErrorStatus import ch.qos.logback.core.status.StatusManager import io.mockk.every import io.mockk.mockk @@ -47,6 +47,6 @@ class AccessLogTests { val accessLog = AccessLog(mockContext, mockArgProvider) accessLog.log() - verify(exactly = 1) { mockStatusManager.add(any()) } + verify(exactly = 1) { mockStatusManager.add(any()) } } } diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyAccessLogFactoryTests.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyAccessLogFactoryTests.kt index b6a5bbb..80ce246 100644 --- a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyAccessLogFactoryTests.kt +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyAccessLogFactoryTests.kt @@ -1,4 +1,113 @@ package io.github.dmitrysulman.logback.access.reactor.netty -// TODO different ways of providing configuration -class ReactorNettyAccessLogFactoryTests +import ch.qos.logback.access.common.joran.JoranConfigurator +import ch.qos.logback.core.status.OnConsoleStatusListener +import io.github.dmitrysulman.logback.access.reactor.netty.ReactorNettyAccessLogFactory.Companion.CONFIG_FILE_NAME_PROPERTY +import io.github.dmitrysulman.logback.access.reactor.netty.integration.EventCaptureAppender +import io.kotest.assertions.throwables.shouldThrowExactly +import io.kotest.matchers.booleans.shouldBeFalse +import io.kotest.matchers.booleans.shouldBeTrue +import io.kotest.matchers.nulls.shouldNotBeNull +import io.kotest.matchers.types.shouldBeTypeOf +import org.junit.jupiter.api.Test +import java.io.FileNotFoundException + +class ReactorNettyAccessLogFactoryTests { + @Test + fun `test default filename configuration`() { + val reactorNettyAccessLogFactory = ReactorNettyAccessLogFactory() + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("DEFAULT") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + } + + @Test + fun `test filename from configuration property`() { + System.setProperty(CONFIG_FILE_NAME_PROPERTY, "logback-access-property.xml") + val reactorNettyAccessLogFactory = ReactorNettyAccessLogFactory() + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("PROPERTY") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + } + + @Test + fun `test filename from constructor parameter as file`() { + val reactorNettyAccessLogFactory = ReactorNettyAccessLogFactory("./src/test/resources/parameter/logback-access-parameter.xml") + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("PARAMETER") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + } + + @Test + fun `test filename from constructor parameter as file with debug true`() { + val reactorNettyAccessLogFactory = + ReactorNettyAccessLogFactory("./src/test/resources/parameter/logback-access-parameter.xml", JoranConfigurator(), true) + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("PARAMETER") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + reactorNettyAccessLogFactory.accessContext.statusManager.copyOfStatusListenerList + .any { + it::class.java == + OnConsoleStatusListener::class.java + }.shouldBeTrue() + } + + @Test + fun `test filename from constructor parameter as resource`() { + val reactorNettyAccessLogFactory = ReactorNettyAccessLogFactory("logback-access-resource.xml") + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("RESOURCE") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + } + + @Test + fun `test filename from constructor parameter as resource with debug true`() { + val reactorNettyAccessLogFactory = ReactorNettyAccessLogFactory("logback-access-resource.xml", JoranConfigurator(), true) + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("RESOURCE") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + reactorNettyAccessLogFactory.accessContext.statusManager.copyOfStatusListenerList + .any { + it::class.java == + OnConsoleStatusListener::class.java + }.shouldBeTrue() + } + + @Test + fun `test file url from constructor parameter`() { + val reactorNettyAccessLogFactory = + ReactorNettyAccessLogFactory(this::class.java.classLoader.getResource("logback-access-url.xml")!!) + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("URL") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + } + + @Test + fun `test file url from constructor parameter with debug true`() { + val reactorNettyAccessLogFactory = + ReactorNettyAccessLogFactory(this::class.java.classLoader.getResource("logback-access-url.xml")!!, JoranConfigurator(), true) + val defaultAppender = reactorNettyAccessLogFactory.accessContext.getAppender("URL") + defaultAppender.shouldNotBeNull() + defaultAppender.shouldBeTypeOf() + reactorNettyAccessLogFactory.accessContext.statusManager.copyOfStatusListenerList + .any { + it::class.java == + OnConsoleStatusListener::class.java + }.shouldBeTrue() + } + + @Test + fun `test not existing filename from configuration property`() { + System.setProperty(CONFIG_FILE_NAME_PROPERTY, "logback-access-not-exist.xml") + val reactorNettyAccessLogFactory = ReactorNettyAccessLogFactory() + reactorNettyAccessLogFactory.accessContext + .iteratorForAppenders() + .hasNext() + .shouldBeFalse() + } + + @Test + fun `test not existing filename from constructor parameter`() { + shouldThrowExactly { ReactorNettyAccessLogFactory("logback-access-not-exist.xml") } + } +} diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapterTests.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapterTests.kt index b05bf63..8cef5b7 100644 --- a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapterTests.kt +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/ReactorNettyServerAdapterTests.kt @@ -1,5 +1,7 @@ package io.github.dmitrysulman.logback.access.reactor.netty +import io.kotest.matchers.longs.shouldBeZero +import io.kotest.matchers.maps.shouldBeEmpty import io.kotest.matchers.shouldBe import io.mockk.every import io.mockk.mockk @@ -12,23 +14,36 @@ import java.time.ZonedDateTime class ReactorNettyServerAdapterTests { @Test fun `smoke test`() { - val mockArgProvider = mockk(relaxed = true) + val mockArgProvider = mockk() every { mockArgProvider.accessDateTime() } returns ZonedDateTime.ofInstant(Instant.ofEpochMilli(1746734856000), ZoneId.of("UTC")) every { mockArgProvider.contentLength() } returns 100 every { mockArgProvider.status() } returns "200" - every { mockArgProvider.responseHeaderIterator() } returns - listOf( - object : Map.Entry { - override val key = "key" - override val value = "value" - }, - ).iterator() + every { mockArgProvider.responseHeaderIterator() } returns headerListIterator() val reactorNettyServerAdapter = ReactorNettyServerAdapter(mockArgProvider) reactorNettyServerAdapter.requestTimestamp shouldBe 1746734856000 reactorNettyServerAdapter.contentLength shouldBe 100 reactorNettyServerAdapter.statusCode shouldBe 200 - reactorNettyServerAdapter.buildResponseHeaderMap() shouldBe mapOf("key" to "value") + reactorNettyServerAdapter.buildResponseHeaderMap() shouldBe + mapOf( + "name1" to "value1", + "name2" to "value2", + "empty_value" to "", + ) + } + + @Test + fun `test on null values`() { + val mockArgProvider = mockk() + every { mockArgProvider.accessDateTime() } returns null + every { mockArgProvider.status() } returns null + every { mockArgProvider.responseHeaderIterator() } returns null + + val reactorNettyServerAdapter = ReactorNettyServerAdapter(mockArgProvider) + + reactorNettyServerAdapter.requestTimestamp.shouldBeZero() + reactorNettyServerAdapter.statusCode shouldBe -1 + reactorNettyServerAdapter.buildResponseHeaderMap().shouldBeEmpty() } } diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/TestsHelper.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/TestsHelper.kt new file mode 100644 index 0000000..60221c2 --- /dev/null +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/TestsHelper.kt @@ -0,0 +1,31 @@ +package io.github.dmitrysulman.logback.access.reactor.netty + +val headerList = + listOf( + object : Map.Entry { + override val key = "name1" + override val value = "value1" + }, + object : Map.Entry { + override val key = "name2" + override val value = "value2" + }, + object : Map.Entry { + override val key = "" + override val value = "empty_name" + }, + object : Map.Entry { + override val key = null + override val value = "null_name" + }, + object : Map.Entry { + override val key = "empty_value" + override val value = "" + }, + object : Map.Entry { + override val key = "null_value" + override val value = null + }, + ) + +fun headerListIterator() = headerList.iterator() diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/IntegrationTests.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/IntegrationTests.kt index 4fbbaf8..4572cc6 100644 --- a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/IntegrationTests.kt +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/IntegrationTests.kt @@ -3,11 +3,25 @@ package io.github.dmitrysulman.logback.access.reactor.netty.integration import ch.qos.logback.access.common.joran.JoranConfigurator import ch.qos.logback.access.common.spi.IAccessEvent import io.github.dmitrysulman.logback.access.reactor.netty.ReactorNettyAccessLogFactory +import io.github.dmitrysulman.logback.access.reactor.netty.enableLogbackAccess +import io.kotest.assertions.nondeterministic.continually +import io.kotest.assertions.nondeterministic.eventually +import io.kotest.matchers.collections.shouldBeEmpty +import io.kotest.matchers.collections.shouldBeSorted +import io.kotest.matchers.collections.shouldBeUnique import io.kotest.matchers.comparables.shouldBeGreaterThan +import io.kotest.matchers.longs.shouldBeGreaterThanOrEqual +import io.kotest.matchers.longs.shouldBeZero import io.kotest.matchers.nulls.shouldNotBeNull import io.kotest.matchers.shouldBe import io.netty.handler.codec.http.HttpHeaderNames.CONTENT_LENGTH import io.netty.handler.codec.http.cookie.DefaultCookie +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.joinAll +import kotlinx.coroutines.launch +import kotlinx.coroutines.reactor.awaitSingleOrNull +import kotlinx.coroutines.runBlocking import org.junit.jupiter.api.AfterEach import org.junit.jupiter.api.BeforeEach import org.junit.jupiter.api.Test @@ -16,22 +30,17 @@ import reactor.netty.DisposableServer import reactor.netty.http.client.HttpClient import reactor.netty.http.client.HttpClientResponse import reactor.netty.http.server.HttpServer -import java.net.InetSocketAddress +import reactor.netty.resources.ConnectionProvider import kotlin.time.Duration.Companion.seconds -import kotlin.time.toJavaDuration -// TODO sequence number -// TODO auth user -// TODO filters class IntegrationTests { private lateinit var server: DisposableServer - private lateinit var eventCaptureAppender: EventCaptureAppender - private var now: Long = 0 + private lateinit var client: HttpClient + private var now = 0L @BeforeEach fun setUp() { now = System.currentTimeMillis() - eventCaptureAppender = EventCaptureAppender() } @AfterEach @@ -40,39 +49,129 @@ class IntegrationTests { } @Test - fun `test basic request`() { - val accessLogFactory = - ReactorNettyAccessLogFactory("logback-access-stdout.xml", JoranConfigurator(), true) - .apply { - accessContext.addAppender(eventCaptureAppender) - } + fun `test basic request`(): Unit = + runBlocking { + val accessLogFactory = + ReactorNettyAccessLogFactory("logback-access-stdout.xml", JoranConfigurator(), true) - server = createServer(accessLogFactory, "mock response") - val response = performGetRequest("/test") - response.shouldNotBeNull() + val eventCaptureAppender = accessLogFactory.accessContext.getAppender("CAPTURE") as EventCaptureAppender + server = createServer(accessLogFactory, "mock response") + client = createClient() + val response = performGetRequest("/test?name=value").awaitSingleOrNull() + response.shouldNotBeNull() + response.status().code() shouldBe 200 - Thread.sleep(100) - eventCaptureAppender.list.size shouldBe 1 - val accessEvent = eventCaptureAppender.list[0] - assertAccessEvent(accessEvent, response) - } + eventually(1.seconds) { + eventCaptureAppender.list.size shouldBe 1 + val accessEvent = eventCaptureAppender.list[0] + accessEvent.sequenceNumber.shouldBeZero() + assertAccessEvent(accessEvent, response) + } + } + + @Test + fun `test filter`(): Unit = + runBlocking { + val accessLogFactory = + ReactorNettyAccessLogFactory("logback-access-filter.xml", JoranConfigurator(), true) + + val eventCaptureAppender = accessLogFactory.accessContext.getAppender("CAPTURE") as EventCaptureAppender + server = createServer(accessLogFactory, "mock response") + client = createClient() + + val responseDeny = performGetRequest("/test?filter=deny").awaitSingleOrNull() + responseDeny.shouldNotBeNull() + responseDeny.status().code() shouldBe 200 + + continually(1.seconds) { + eventCaptureAppender.list.shouldBeEmpty() + } + + val responseAccept = performGetRequest("/test?filter=accept").awaitSingleOrNull() + responseAccept.shouldNotBeNull() + responseAccept.status().code() shouldBe 200 + + eventually(1.seconds) { + eventCaptureAppender.list.size shouldBe 1 + val accessEvent = eventCaptureAppender.list[0] + assertAccessEvent(accessEvent, responseAccept) + } + + val responseNeutral = performGetRequest("/test?filter=neutral").awaitSingleOrNull() + responseNeutral.shouldNotBeNull() + responseNeutral.status().code() shouldBe 200 + + eventually(1.seconds) { + eventCaptureAppender.list.size shouldBe 2 + val accessEvent = eventCaptureAppender.list[1] + assertAccessEvent(accessEvent, responseNeutral) + } + } + + @Test + fun `test sequence number generator`(): Unit = + runBlocking { + val accessLogFactory = + ReactorNettyAccessLogFactory("logback-access-sequence-number-generator.xml", JoranConfigurator(), true) + + val eventCaptureAppender = accessLogFactory.accessContext.getAppender("CAPTURE") as EventCaptureAppender + server = createServer(accessLogFactory, "") + client = createClient() + + repeat(50) { + val response = performGetRequest("/test").awaitSingleOrNull() + response.shouldNotBeNull() + response.status().code() shouldBe 200 + } + + eventually(1.seconds) { + eventCaptureAppender.list.size shouldBe 50 + eventCaptureAppender.list + .sortedBy { it.timeStamp } + .map { it.sequenceNumber } + .shouldBeUnique() + .shouldBeSorted() + } + } + + @Test + fun `performance test`(): Unit = + runBlocking { + val accessLogFactory = + ReactorNettyAccessLogFactory("logback-access-capture.xml", JoranConfigurator(), true) + + val eventCaptureAppender = accessLogFactory.accessContext.getAppender("CAPTURE") as EventCaptureAppender + server = createServer(accessLogFactory, "test") + client = createClient() + + val jobs = + (1..5000).map { + CoroutineScope(Dispatchers.Default).launch { + val response = performGetRequest("/test").awaitSingleOrNull() + response.shouldNotBeNull() + response.status().code() shouldBe 200 + } + } + jobs.joinAll() + eventually(5.seconds) { eventCaptureAppender.list.size shouldBe jobs.size } + } private fun assertAccessEvent( accessEvent: IAccessEvent, response: HttpClientResponse, ) { accessEvent.requestURL shouldBe "${response.method().name()} ${response.uri()} ${response.version().text()}" - accessEvent.requestURI shouldBe response.uri() + accessEvent.requestURI shouldBe response.fullPath() accessEvent.localPort shouldBe server.port() accessEvent.remoteHost shouldBe response.responseHeaders().get(REMOTE_HOST_HEADER) accessEvent.remoteAddr shouldBe response.responseHeaders().get(REMOTE_ADDRESS_HEADER) - accessEvent.queryString shouldBe "" + accessEvent.queryString shouldBe + if (response.uri().indexOf("?") != -1) response.uri().substring(response.uri().indexOf("?")) else "" accessEvent.protocol shouldBe response.version().text() accessEvent.method shouldBe response.method().name() accessEvent.statusCode shouldBe response.status().code() - accessEvent.elapsedTime shouldBeGreaterThan 0 + accessEvent.elapsedTime shouldBeGreaterThanOrEqual 0 accessEvent.timeStamp shouldBeGreaterThan now - accessEvent.sequenceNumber shouldBe 0 accessEvent.remoteUser shouldBe "-" accessEvent.getRequestHeader(TEST_REQUEST_HEADER_NAME) shouldBe TEST_REQUEST_HEADER_VALUE accessEvent.getResponseHeader(TEST_RESPONSE_HEADER_NAME) shouldBe TEST_RESPONSE_HEADER_VALUE @@ -83,30 +182,38 @@ class IntegrationTests { private fun createServer( accessLogFactory: ReactorNettyAccessLogFactory, responseContent: String, - ): DisposableServer = - HttpServer - .create() - .handle { request, response -> - val remoteHost = (request.remoteAddress() as InetSocketAddress).hostString - val remoteAddress = (request.remoteAddress() as InetSocketAddress).address.hostAddress - response - .addHeader(REMOTE_HOST_HEADER, remoteHost) - .addHeader(REMOTE_ADDRESS_HEADER, remoteAddress) - .addHeader(TEST_RESPONSE_HEADER_NAME, TEST_RESPONSE_HEADER_VALUE) - .sendByteArray(Mono.just(responseContent.toByteArray())) - }.accessLog(true, accessLogFactory) - .bindNow() - - private fun performGetRequest(uri: String): HttpClientResponse? = - HttpClient - .create() + ) = HttpServer + .create() + .enableLogbackAccess(accessLogFactory) + .handle { request, response -> + val remoteHost = request.remoteAddress()!!.hostString + val remoteAddress = request.remoteAddress()!!.address.hostAddress + response + .addHeader(REMOTE_HOST_HEADER, remoteHost) + .addHeader(REMOTE_ADDRESS_HEADER, remoteAddress) + .addHeader(TEST_RESPONSE_HEADER_NAME, TEST_RESPONSE_HEADER_VALUE) + .sendByteArray(Mono.just(responseContent.toByteArray())) + }.bindNow() + + private fun createClient(): HttpClient { + val connectionProvider = + ConnectionProvider + .builder("provider") + .maxConnections(50) + .pendingAcquireMaxCount(5000) + .build() + return HttpClient + .create(connectionProvider) + } + + private fun performGetRequest(uri: String): Mono = + client .port(server.port()) .headers { it.add(TEST_REQUEST_HEADER_NAME, TEST_REQUEST_HEADER_VALUE) } .cookie(DefaultCookie(TEST_COOKIE_NAME, TEST_COOKIE_VALUE)) .get() .uri(uri) .response() - .block(30.seconds.toJavaDuration()) companion object { private const val REMOTE_HOST_HEADER = "Remote-Host" diff --git a/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/TestFilter.kt b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/TestFilter.kt new file mode 100644 index 0000000..50548de --- /dev/null +++ b/logback-access-reactor-netty/src/test/kotlin/io/github/dmitrysulman/logback/access/reactor/netty/integration/TestFilter.kt @@ -0,0 +1,15 @@ +package io.github.dmitrysulman.logback.access.reactor.netty.integration + +import ch.qos.logback.access.common.spi.IAccessEvent +import ch.qos.logback.core.filter.Filter +import ch.qos.logback.core.spi.FilterReply + +class TestFilter : Filter() { + override fun decide(event: IAccessEvent) = + event + .getRequestParameter("filter") + ?.firstOrNull() + ?.let { filterParam -> + FilterReply.entries.find { it.name.equals(filterParam, true) } + } ?: FilterReply.NEUTRAL +} diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-capture.xml b/logback-access-reactor-netty/src/test/resources/logback-access-capture.xml new file mode 100644 index 0000000..ede3a71 --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access-capture.xml @@ -0,0 +1,4 @@ + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-filter.xml b/logback-access-reactor-netty/src/test/resources/logback-access-filter.xml new file mode 100644 index 0000000..9d1f714 --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access-filter.xml @@ -0,0 +1,7 @@ + + + + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-property.xml b/logback-access-reactor-netty/src/test/resources/logback-access-property.xml new file mode 100644 index 0000000..23fcb0c --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access-property.xml @@ -0,0 +1,4 @@ + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-resource.xml b/logback-access-reactor-netty/src/test/resources/logback-access-resource.xml new file mode 100644 index 0000000..38457de --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access-resource.xml @@ -0,0 +1,4 @@ + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-sequence-number-generator.xml b/logback-access-reactor-netty/src/test/resources/logback-access-sequence-number-generator.xml new file mode 100644 index 0000000..5797e0c --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access-sequence-number-generator.xml @@ -0,0 +1,6 @@ + + + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-stdout.xml b/logback-access-reactor-netty/src/test/resources/logback-access-stdout.xml index d9636dc..d5a903b 100644 --- a/logback-access-reactor-netty/src/test/resources/logback-access-stdout.xml +++ b/logback-access-reactor-netty/src/test/resources/logback-access-stdout.xml @@ -1,9 +1,11 @@ + common + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access-url.xml b/logback-access-reactor-netty/src/test/resources/logback-access-url.xml new file mode 100644 index 0000000..9f29240 --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access-url.xml @@ -0,0 +1,4 @@ + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-access.xml b/logback-access-reactor-netty/src/test/resources/logback-access.xml new file mode 100644 index 0000000..0fa354a --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/logback-access.xml @@ -0,0 +1,4 @@ + + + + \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/logback-test.xml b/logback-access-reactor-netty/src/test/resources/logback-test.xml index e6cd160..7107031 100644 --- a/logback-access-reactor-netty/src/test/resources/logback-test.xml +++ b/logback-access-reactor-netty/src/test/resources/logback-test.xml @@ -1,5 +1,4 @@ - %d{HH:mm:ss.SSS} [%.-20thread] %-5level %logger{36} - %msg%n @@ -7,7 +6,6 @@ - + - \ No newline at end of file diff --git a/logback-access-reactor-netty/src/test/resources/parameter/logback-access-parameter.xml b/logback-access-reactor-netty/src/test/resources/parameter/logback-access-parameter.xml new file mode 100644 index 0000000..692ba85 --- /dev/null +++ b/logback-access-reactor-netty/src/test/resources/parameter/logback-access-parameter.xml @@ -0,0 +1,4 @@ + + + + \ No newline at end of file