https://kotlinlang.org logo
#ktor
Title
# ktor
g

gotoOla

09/08/2020, 1:17 PM
Hi everybody! Going for a question here as I'm out of luck in my debugging of this weird behavior. Just putting it out here to see if anybody else has experienced or seen something similar or has some good advice on where to go next We are getting requests in to a ktor server, that in turn then calls 3 other services using three different instantiations of ktor client. We regularly see that we get IOException: Connection reset by peer in the calls we are making. I started to add some traceId parameters to the calls to be able to see what happened in the other services (remember, these are three unrelated services but each of them gave this error every once in a while) but it seems the calls never found their way to these services, making me think that there is maybe a bug in the internal ktor client? We tried it with both Apache and CIO as an engine and got the same result. Now I changed to OkHttpClient and I don't see this anymore
Copy code
stack_trace	   	java.io.IOException: Connection reset by peer
	at (Coroutine boundary.()
	at io.ktor.client.engine.apache.ApacheEngine.execute(ApacheEngine.kt:23)
	at io.ktor.client.engine.HttpClientEngine$install$1.invokeSuspend(HttpClientEngine.kt:49)
	at io.ktor.client.features.HttpSend$DefaultSender.execute(HttpSend.kt:90)
	at io.ktor.client.features.HttpSend$Feature$install$1.invokeSuspend(HttpSend.kt:62)
	at io.ktor.client.HttpClient.execute(HttpClient.kt:141)
	at io.ktor.client.call.HttpClientCallKt.call(HttpClientCall.kt:140)
	at mycompany.clients.SearchClient.getSearch(SearchClient.kt:76)
	at mycompany.services.SearchService$getPrerequisits$2.invokeSuspend(SearchService.kt:28)
	at mycompany.endpoints.SearchEndpoints$createRoutes$1$1$2.invokeSuspend(ExportEndpoints.kt:61)
	at mycompany.core.ktor.Router_extensionsKt$postAndReportMetrics$2.invokeSuspend(router_extensions.kt:57)
	at io.ktor.routing.Routing.executeResult(Routing.kt:147)
	at io.ktor.routing.Routing$Feature$install$1.invokeSuspend(Routing.kt:99)
	at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$2.invokeSuspend(DefaultEnginePipeline.kt:118)
	at io.ktor.server.netty.NettyApplicationCallHandler$handleRequest$1.invokeSuspend(NettyApplicationCallHandler.kt:36)
Caused by: java.io.IOException: Connection reset by peer
	at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
	at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
	at sun.nio.ch.IOUtil.read(IOUtil.java:197)
	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:377)
	at org.apache.http.nio.reactor.ssl.SSLIOSession.receiveEncryptedData(SSLIOSession.java:444)
	at org.apache.http.nio.reactor.ssl.SSLIOSession.isAppInputReady(SSLIOSession.java:499)
	at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:120)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
	at java.lang.Thread.run(Thread.java:748)
t tags	   	logstash
t thread_name	   	DefaultDispatcher-worker-7 @call-handler#3553
This is running with ktor 1.2.4, also tried to bump it to 1.4.0 but saw the same issues there
m

mserralta

09/08/2020, 1:42 PM
maybe your services have some sort of "client_inactivity_timeout" that closes Idle clients after X seconds of inactivity? i encountered this error connecting to my logstash service when trying to send logs from filebeat. 🤷🏻
g

gotoOla

09/08/2020, 1:50 PM
do you mean the service that I have that is sending the calls?
m

mserralta

09/08/2020, 2:30 PM
the service receiving the calls
g

gotoOla

09/08/2020, 6:35 PM
seems to be a bug with the apache-engine and ktor-client somehow... first rewrote the http implementation using the ordinary OkHttp-client instead and didn't see problems anymore... now I changed to just using the OkHttpEngine and seems that it got fixed by that
r

rrva

09/09/2020, 4:30 AM
Due to very similar issues (over time, ktor client engine for apache stops sending requests) we decided to use our own client wrapper around the Java Http Client included in jdk11+ (https://openjdk.java.net/groups/net/httpclient/recipes.html) and we use the client
sendAsync
call which returns a
CompletableFuture
combined with the extension function
suspend fun <T> CompletionStage<T>.await()
https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-jdk8/kotlinx.coroutines.future/java.util.concurrent.-completion-stage/await.html to convert this to a suspending call. Did you create a youtrack ticket for this?
I’m also interested in if we can create a small reproducer project for this issue, haven’t been able to yet.
I created a small project as a skeleton. I would like to reproduce the issue that the apache engine stops sending requests due to I/O exceptions possibly putting all the connection workers in a bad state: https://github.com/rrva/ktor-client-connection-leak/blob/master/src/main/kotlin/se/rrva/Client.kt
Did you report this at https://youtrack.jetbrains.com/ ?
g

gotoOla

09/18/2020, 9:38 AM
I did not, I have to find the time to put together all the info
don't know how much I can provide either... but I guess the fact that it happens should be enough for it to start gain some traction
r

rrva

09/20/2020, 9:39 PM
thanks, i’ve linked it from one of my issues
5 Views