Proxy throws 500 after timed out connection

[davyskiba]

After running Subscriber NetwrokConnectivityTests for TcpConnectionUnresponsive when one of them timed out on the next run proxy failed to respond to requests with the following error:

2023-03-03 14:20:04.846 [DefaultDispatcher-worker-17] DEBUG ktor.application - Unhandled: POST - /faults/TcpConnectionUnresponsive/simulation. Exception class java.net.BindException: Address already in use] java.net.BindException: Address already in use at java.base/sun.nio.ch.Net.bind0(Native Method) at java.base/sun.nio.ch.Net.bind(Net.java:555) at java.base/sun.nio.ch.Net.bind(Net.java:544) at java.base/sun.nio.ch.NioSocketImpl.bind(NioSocketImpl.java:643) at java.base/java.net.ServerSocket.bind(ServerSocket.java:388) at java.base/java.net.ServerSocket.(ServerSocket.java:274) at java.base/java.net.ServerSocket.(ServerSocket.java:167) at com.ably.tracking.test.Layer4Proxy.start(AblyProxy.kt:129) at com.ably.tracking.test.plugins.RoutingKt$configureRouting$1$2.invokeSuspend(Routing.kt:60) at com.ably.tracking.test.plugins.RoutingKt$configureRouting$1$2.invoke(Routing.kt) at com.ably.tracking.test.plugins.RoutingKt$configureRouting$1$2.invoke(Routing.kt) at io.ktor.server.routing.Route$buildPipeline$1$1.invokeSuspend(Route.kt:116) at io.ktor.server.routing.Route$buildPipeline$1$1.invoke(Route.kt) at io.ktor.server.routing.Route$buildPipeline$1$1.invoke(Route.kt) at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:120) at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.kt:78) at io.ktor.util.pipeline.SuspendFunctionGun.execute$ktor_utils(SuspendFunctionGun.kt:98) at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:77) at io.ktor.server.routing.Routing$executeResult$$inlined$execute$1.invokeSuspend(Pipeline.kt:478) at io.ktor.server.routing.Routing$executeResult$$inlined$execute$1.invoke(Pipeline.kt) at io.ktor.server.routing.Routing$executeResult$$inlined$execute$1.invoke(Pipeline.kt) at io.ktor.util.debug.ContextUtilsKt.initContextInDebugMode(ContextUtils.kt:17) at io.ktor.server.routing.Routing.executeResult(Routing.kt:190) at io.ktor.server.routing.Routing.interceptor(Routing.kt:64) at io.ktor.server.routing.Routing$Plugin$install$1.invokeSuspend(Routing.kt:140) at io.ktor.server.routing.Routing$Plugin$install$1.invoke(Routing.kt) at io.ktor.server.routing.Routing$Plugin$install$1.invoke(Routing.kt) at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:120) at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.kt:78) at io.ktor.server.engine.BaseApplicationEngineKt$installDefaultTransformationChecker$1.invokeSuspend(BaseApplicationEngine.kt:123) at io.ktor.server.engine.BaseApplicationEngineKt$installDefaultTransformationChecker$1.invoke(BaseApplicationEngine.kt) at io.ktor.server.engine.BaseApplicationEngineKt$installDefaultTransformationChecker$1.invoke(BaseApplicationEngine.kt) at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:120) at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.kt:78) at io.ktor.util.pipeline.SuspendFunctionGun.execute$ktor_utils(SuspendFunctionGun.kt:98) at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:77) at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$1$invokeSuspend$$inlined$execute$1.invokeSuspend(Pipeline.kt:478) at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$1$invokeSuspend$$inlined$execute$1.invoke(Pipeline.kt) at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$1$invokeSuspend$$inlined$execute$1.invoke(Pipeline.kt) at io.ktor.util.debug.ContextUtilsKt.initContextInDebugMode(ContextUtils.kt:17) at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$1.invokeSuspend(DefaultEnginePipeline.kt:118) at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$1.invoke(DefaultEnginePipeline.kt) at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$1.invoke(DefaultEnginePipeline.kt) at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:120) at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.kt:78) at io.ktor.util.pipeline.SuspendFunctionGun.execute$ktor_utils(SuspendFunctionGun.kt:98) at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:77) at io.ktor.server.cio.CIOApplicationEngine$handleRequest$2$invokeSuspend$$inlined$execute$1.invokeSuspend(Pipeline.kt:478) at io.ktor.server.cio.CIOApplicationEngine$handleRequest$2$invokeSuspend$$inlined$execute$1.invoke(Pipeline.kt) at io.ktor.server.cio.CIOApplicationEngine$handleRequest$2$invokeSuspend$$inlined$execute$1.invoke(Pipeline.kt) at io.ktor.util.debug.ContextUtilsKt.initContextInDebugMode(ContextUtils.kt:17) at io.ktor.server.cio.CIOApplicationEngine$handleRequest$2.invokeSuspend(CIOApplicationEngine.kt:191) at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) at kotlinx.coroutines.internal.LimitedDispatcher.run(LimitedDispatcher.kt:42) at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:95) at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570) at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750) at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677) at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664) 2023-03-03 14:20:04.847 [DefaultDispatcher-worker-17] INFO ktor.application - 500 Internal Server Error: POST - /faults/TcpConnectionUnresponsive/simulation in 3ms

[lawrence-forooghian]

@davyskiba to be able to create a new proxy, you must first clean up the previous one using the /fault-simulations/{id}/clean-up endpoint, else you'll get this error. Could you please confirm that this happened? The subscriber network connectivity tests on Android appear to perform this as part of tearDown.

[davyskiba]

It probably did not because one of the tests was hanging indefinitely, and I have manually interrupted it 😄 Maybe we could add a message about that to all 500 errors?

[lawrence-forooghian]

Do you mean to add it in the response from the server (I'm not sure if it already contains an error message or not), or in the tests? For sure it would be good for the user to have some way of knowing what's gone wrong, though.

[davyskiba]

We could add it to the following:

• the exception that is raised in the server logs
• the error response that comes from the server and is logged in tests, I think currently it is some generic 500 message