From 010b9f61924462d2baf861a5ec3602c7435157c8 Mon Sep 17 00:00:00 2001 From: fru1tworld Date: Wed, 29 Apr 2026 16:53:36 +0900 Subject: [PATCH 1/2] KTOR-646 Log client-disconnect IOException at TRACE in Netty HTTP/1 handler --- .../server/netty/http1/NettyHttp1Handler.kt | 2 +- .../tests/server/netty/NettySpecificTest.kt | 57 +++++++++++++++++++ 2 files changed, 58 insertions(+), 1 deletion(-) diff --git a/ktor-server/ktor-server-netty/jvm/src/io/ktor/server/netty/http1/NettyHttp1Handler.kt b/ktor-server/ktor-server-netty/jvm/src/io/ktor/server/netty/http1/NettyHttp1Handler.kt index cdbc2994828..745fb116d83 100644 --- a/ktor-server/ktor-server-netty/jvm/src/io/ktor/server/netty/http1/NettyHttp1Handler.kt +++ b/ktor-server/ktor-server-netty/jvm/src/io/ktor/server/netty/http1/NettyHttp1Handler.kt @@ -104,7 +104,7 @@ internal class NettyHttp1Handler( override fun exceptionCaught(context: ChannelHandlerContext, cause: Throwable) { when (cause) { is IOException -> { - environment.log.debug("I/O operation failed", cause) + environment.log.trace("I/O operation failed", cause) handlerJob.cancel() context.close() } diff --git a/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt b/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt index c4835fa4e10..cc5b9674747 100644 --- a/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt +++ b/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt @@ -4,6 +4,10 @@ package io.ktor.tests.server.netty +import ch.qos.logback.classic.Level +import ch.qos.logback.classic.Logger +import ch.qos.logback.classic.spi.ILoggingEvent +import ch.qos.logback.core.read.ListAppender import io.ktor.client.* import io.ktor.client.engine.cio.* import io.ktor.client.plugins.* @@ -16,14 +20,20 @@ import io.ktor.server.application.* import io.ktor.server.application.hooks.* import io.ktor.server.engine.* import io.ktor.server.netty.* +import io.ktor.server.netty.http1.NettyHttp1Handler import io.ktor.server.response.* import io.ktor.server.routing.* import io.ktor.test.dispatcher.* import io.ktor.utils.io.* +import io.mockk.mockk +import io.netty.channel.embedded.EmbeddedChannel import kotlinx.coroutines.* +import org.slf4j.LoggerFactory +import java.io.IOException import java.net.BindException import java.net.ServerSocket import java.util.concurrent.ExecutorService +import kotlin.coroutines.EmptyCoroutineContext import kotlin.test.* import kotlin.time.Duration.Companion.seconds @@ -171,6 +181,53 @@ class NettySpecificTest { } } + @Test + fun `KTOR-646 client-disconnect IOException is logged at TRACE not DEBUG`() { + val logger = LoggerFactory.getLogger("io.ktor.tests.server.netty.KTOR-646") as Logger + val previousLevel = logger.level + val listAppender = ListAppender().apply { start() } + logger.level = Level.TRACE + logger.addAppender(listAppender) + + val environment = applicationEnvironment { log = logger } + val handler = NettyHttp1Handler( + applicationProvider = { mockk(relaxed = true) }, + enginePipeline = mockk(relaxed = true), + environment = environment, + engineContext = EmptyCoroutineContext, + userContext = EmptyCoroutineContext, + runningLimit = 32 + ) + + // EmbeddedChannel without firing the full pipeline lifecycle: we only + // want to exercise exceptionCaught. Use a fresh channel and add only + // this handler so RequestBodyHandler isn't installed via channelActive. + val channel = EmbeddedChannel() + channel.pipeline().addLast(handler) + try { + channel.pipeline().fireExceptionCaught(IOException("Connection reset by peer")) + + logger.detachAppender(listAppender) + + val ioOpFailedEvents = listAppender.list.filter { it.formattedMessage == "I/O operation failed" } + assertEquals( + 1, + ioOpFailedEvents.size, + "Expected one 'I/O operation failed' log entry for client-disconnect IOException, " + + "got ${ioOpFailedEvents.size}" + ) + assertEquals( + Level.TRACE, + ioOpFailedEvents.single().level, + "Client-disconnect IOException must be logged at TRACE to avoid noise in DEBUG logs" + ) + } finally { + logger.detachAppender(listAppender) + logger.level = previousLevel + channel.finishAndReleaseAll() + } + } + @Test fun badRequestOnInvalidQueryString() = runTestWithRealTime { val appStarted = CompletableDeferred() From d6162313b665e447e47b95396b741445083ce9bd Mon Sep 17 00:00:00 2001 From: fru1tworld Date: Thu, 30 Apr 2026 17:55:40 +0900 Subject: [PATCH 2/2] Address review feedback: simplify test name and remove redundant detach --- .../test/io/ktor/tests/server/netty/NettySpecificTest.kt | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt b/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt index cc5b9674747..1eb4b2c0977 100644 --- a/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt +++ b/ktor-server/ktor-server-netty/jvm/test/io/ktor/tests/server/netty/NettySpecificTest.kt @@ -182,8 +182,8 @@ class NettySpecificTest { } @Test - fun `KTOR-646 client-disconnect IOException is logged at TRACE not DEBUG`() { - val logger = LoggerFactory.getLogger("io.ktor.tests.server.netty.KTOR-646") as Logger + fun `client disconnect is logged at trace level`() { + val logger = LoggerFactory.getLogger("io.ktor.tests.server.netty.ClientDisconnectLogging") as Logger val previousLevel = logger.level val listAppender = ListAppender().apply { start() } logger.level = Level.TRACE @@ -207,8 +207,6 @@ class NettySpecificTest { try { channel.pipeline().fireExceptionCaught(IOException("Connection reset by peer")) - logger.detachAppender(listAppender) - val ioOpFailedEvents = listAppender.list.filter { it.formattedMessage == "I/O operation failed" } assertEquals( 1,