Skip to content

Failed stream request hangs until timeout #1973

Open
@reimai

Description

@reimai

Hi, I'm using async-http-client 2.12.3 for stream requests. Suddenly all failed requests are cancelled by timeout (1m).
Debugging the issue shows that these requests are actually failing almost immediately due to a closed channel, but unsuccessfully recovered with a warning of a closed stream to time out a minute later:

2024-07-30 17:56:25.809 | zio-default-blocking-35   org.asynchttpclient.netty.request.NettyRequestSender   Using pooled Channel '[id: 0x64b880e7, L:/[my-client-ip]:56122 - R:my-server/[my-ip]:8443]' for 'POST' to my server

2024-07-30 17:56:25.809 | zio-default-blocking-35   org.asynchttpclient.netty.request.NettyRequestSender   Using open Channel [id: 0x64b880e7, L:/[my-client-ip]:56122 - my-sever/[my-ip]:8443] for POST 

2024-07-30 17:56:25.898 | AsyncHttpClient-4-1   org.asynchttpclient.netty.request.WriteListener   Write exception on pooled channel, letting retry trigger    stack_trace: java.nio.channels.ClosedChannelException: null

2024-07-30 17:56:25.899 | AsyncHttpClient-4-1   org.asynchttpclient.netty.handler.HttpHandler   Channel Closed: [id: 0x64b880e7, L:/[my-client-ip]:56122 ! my-server/[my-ip]:8443] with attribute NettyResponseFuture{currentRetry=0, 	isDone=0, 	isCancelled=0, 	asyncHandler=sttp.client3.asynchttpclient.AsyncHttpClientBackend$$anon$1@22721d20, 	nettyRequest=org.asynchttpclient.netty.request.NettyRequest@5f78e6db, 	future=java.util.concurrent.CompletableFuture@481ada03[Not completed], 	uri=my-server:8443?query=INSERT+INTO+profiler_collector.samples+(mode,+service_name,+timestamp,+labels.key,+labels.value,%0A++stack_trace.method_id,+stack_trace.line,+stack_trace.type,+samples)%0AVALUES%0A, 	keepAlive=true, 	redirectCount=0, 	timeoutsHolder=org.asynchttpclient.netty.timeout.TimeoutsHolder@1bfcc8d7, 	inAuth=0, 	touch=1722351385898}

2024-07-30 17:56:25.899 | AsyncHttpClient-4-1   org.asynchttpclient.netty.request.NettyRequestSender   Trying to recover request DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)

2024-07-30 17:56:25.907 | AsyncHttpClient-4-3   org.asynchttpclient.netty.channel.NettyConnectListener   Using new Channel '[id: 0xba9d5427, L:/[my-client-ip]:57472 - my-server/[my-ip]:8443]' for 'POST' to my-server

2024-07-30 17:56:25.908 | AsyncHttpClient-4-3   org.asynchttpclient.netty.request.body.NettyReactiveStreamsBody   Stream has already been consumed and cannot be reset

2024-07-30 17:57:25.932 | AsyncHttpClient-timer-3-1   org.asynchttpclient.netty.request.NettyRequestSender   Request timeout to my-server/my-ip:8443 after 60000 ms 

Setting maxRetries to 0 and retrying requests outside of async-http-client solves the issue, requests are retried immediately and successfully.
Should NettyReactiveStreamsBody just log a warning for an already consumed stream? Why would not it cancel the response Future and maybe close the Channel, so the user would not wait for a timeout?

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions