marcellustavares opened a new issue, #705: URL: https://github.com/apache/pekko-http/issues/705
Hi team, I’m investigating an issue in my application server logs, and I can see several entries related to abrupt connection interruptions before server response. I've tried to simulate the error locally by configuring a server keepAlive timeout to 5s and I can see a similar error in the logs. The server closes the connection between request 2 and 3, however Pekko apparently does not recover and fails the third request. I was wondering if Pekko should verify the connection state before failing the request? Any insights are appreciated. Thanks _Client.log_ ``` [Client] Sending 2 request at 09:04:07.715981 15546 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - Dispatching request [GET / Empty] to pool 15546 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Idle)]Dispatching request [GET / Empty] 15546 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Idle)]Before event [onNewRequest] In state [Idle] for [3448 ms] 15547 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (PushingRequestToConnection)]After event [onNewRequest] State change [Idle] -> [PushingRequestToConnection] 15547 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (PushingRequestToConnection)]Before event [onRequestDispatched] In state [PushingRequestToConnection] for [0 ms] 15547 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]After event [onRequestDispatched] State change [PushingRequestToConnection] -> [WaitingForResponse] 20554 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]Received response 20555 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]Before event [onResponseReceived] In state [WaitingForResponse] for [5007 ms] 20555 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]onResponseReceived in WaitingForResponse with false 20555 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponseDispatch)]After event [onResponseReceived] State change [WaitingForResponse] -> [WaitingForResponseDispatch] 20555 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponseDispatch)]Before event [onResponseDispatchable] In state [WaitingForResponseDispatch] for [0 ms] 20556 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponseEntitySubscription)]After event [onResponseDispatchable] State change [WaitingForResponseDispatch] -> [WaitingForResponseEntitySubscription] 20556 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponseEntitySubscription)]Before event [onResponseEntitySubscribed] In state [WaitingForResponseEntitySubscription] for [0 ms] 20556 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForEndOfResponseEntity)]After event [onResponseEntitySubscribed] State change [WaitingForResponseEntitySubscription] -> [WaitingForEndOfResponseEntity] 20556 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForEndOfResponseEntity)]Before event [onResponseEntityCompleted] In state [WaitingForEndOfResponseEntity] for [0 ms] 20556 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-6] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Idle)]After event [onResponseEntityCompleted] State change [WaitingForEndOfResponseEntity] -> [Idle] 20556 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-8] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Idle)]Slot became idle... Trying to pull [Client] 2 Response: 200 OK at 09:04:12.727531 [Client] Sending 3 request at 09:04:20.548659 28379 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - Dispatching request [GET / Empty] to pool 28379 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Idle)]Dispatching request [GET / Empty] 28379 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Idle)]Before event [onNewRequest] In state [Idle] for [7823 ms] 28379 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (PushingRequestToConnection)]After event [onNewRequest] State change [Idle] -> [PushingRequestToConnection] 28379 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (PushingRequestToConnection)]Before event [onRequestDispatched] In state [PushingRequestToConnection] for [0 ms] 28379 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]After event [onRequestDispatched] State change [PushingRequestToConnection] -> [WaitingForResponse] 28383 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]Connection failed 28383 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]Before event [onConnectionFailed] In state [WaitingForResponse] for [3 ms] 28383 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponse)]Ongoing request [GET / Empty] is failed because of [connection failure]: [The http server closed the connection unexpectedly before delivering responses for 1 outstanding requests] 28383 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponseDispatch)]After event [onConnectionFailed] State change [WaitingForResponse] -> [WaitingForResponseDispatch] 28383 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (WaitingForResponseDispatch)]Before event [onResponseDispatchable] In state [WaitingForResponseDispatch] for [0 ms] 28383 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Failed)]After event [onResponseDispatchable] State change [WaitingForResponseDispatch] -> [Failed] 28384 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Failed)]State change from [WaitingForResponseDispatch] to [Failed(org.apache.pekko.http.impl.engine.client.OutgoingConnectionBlueprint$UnexpectedConnectionClosureException: The http server closed the connection unexpectedly before delivering responses for 1 outstanding requests)]. Closing the existing connection. 28385 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Unconnected)]Slot became idle... Trying to pull 28385 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Unconnected)]Preconnecting because number of connected slots fell down to 0 28385 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Unconnected)]Before event [onPreConnect] In state [Unconnected] for [0 ms] 28385 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (Unconnected)]Establishing connection 28386 [PekkoHttpClientReproducer-pekko.actor.default-dispatcher-5] DEBUG org.apache.pekko.http.impl.engine.client.PoolId - [0 (PreConnecting)]After event [onPreConnect] State change [Unconnected] -> [PreConnecting] [Client] 3 Failed: The http server closed the connection unexpectedly before delivering responses for 1 outstanding requests at 09:04:20.556410 unknown exception The http server closed the connection unexpectedly before delivering responses for 1 outstanding requests ``` _Server.log_ ``` [Server] NEW connection from ::ffff:127.0.0.1:57861 at 9:03:52 AM incoming request #0 responding request #0 request closed incoming request #1 responding request #1 request closed incoming request #2 responding request #2 request closed [Server] CLOSE Connection ::ffff:127.0.0.1:57861 at 9:04:18 AM [Server] NEW connection from ::ffff:127.0.0.1:57877 at 9:04:33 AM incoming request #4 responding request #4 request closed [Server] CLOSE Connection ::ffff:127.0.0.1:57877 at 9:04:44 AM ``` -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: notifications-unsubscr...@pekko.apache.org.apache.org For queries about this service, please contact Infrastructure at: us...@infra.apache.org --------------------------------------------------------------------- To unsubscribe, e-mail: notifications-unsubscr...@pekko.apache.org For additional commands, e-mail: notifications-h...@pekko.apache.org
