Transfer-Encoding: chunked in response header and channel reuse

[YurZir]

Hello,

we face the following issue with AsyncHttpClient. When the response is chunked, using of the open channel from the previous request does not work and runs into timeout delaying the HTTP request.

Situation:

Application sends request A to a remote destination

2021 03 18 09:35:42#+00#DEBUG#org.asynchttpclient.netty.channel.NettyConnectListener##xxx#AsyncHttpClient-113-4###ed86a5e0a#na#na#na#na#Using new Channel '[id: 0x6b4eed08, L:/SOURCE_IP:39394 - R:DEST_HOST/IP:443]' for 'GET' to '/url'|

Here request A is sent and response received (quickly, 200 ms) with Transfer-Encoding: chunked!!!

2021 03 18 09:35:42#+00#TRACE#io.netty.handler.logging.LoggingHandler##xxx#AsyncHttpClient-113-4###ed86a5e0a#na#na#na#na#[id: 0x6b4eed08, L:/SOURCE_IP:39394 - R:DEST_HOST/IP:443] READ: 3875B

Netty is actually still waiting for the next chunk of HTTP response, but the channel is immediately added to the pool

2021 03 18 09:35:43#+00#DEBUG#org.asynchttpclient.netty.channel.ChannelManager##xxx#AsyncHttpClient-113-4###ed86a5e0a#na#na#na#na#Adding key: https://DEST_HOST:443 for channel [id: 0x6b4eed08, L:/SOURCE_IP:39394 - R:eu.DEST_HOST/IP:443]| 2021 03 18 09:35:43#+00#DEBUG#org.asynchttpclient.netty.channel.DefaultChannelPool##anonymous#AsyncHttpClient-timer-112-1####na#na#na#na#Entry count for : https://DEST_HOST:443 : 1|

Application decides to send the next request B to the same destination Pooled channel is used, although Netty is still waiting for the next chunk of request A!

2021 03 18 09:35:44#+00#DEBUG#org.asynchttpclient.netty.request.NettyRequestSender##xxx#default-workqueue-6###ed86a5e0a#na#na#na#na#Using pooled Channel '[id: 0x6b4eed08, L:/SOURCE_IP:39394 - R:DEST_HOST/IP:443]' for 'GET' to 'https://DEST_HOST/url'| 2021 03 18 09:35:44#+00#DEBUG#org.asynchttpclient.netty.request.NettyRequestSender##xxx#default-workqueue-6###ed86a5e0a#na#na#na#na#Using open Channel [id: 0x6b4eed08, L:/SOURCE_IP:39394 - R:DEST_HOST/IP:443] for GET '/url'|

The request B is not actually sent out because Netty is still busy waiting for the next chunk from the previous request

After around 3 minutes of waiting Netty figures out that no further chunks will come and the READ operation is finally complete for the request A:

2021 03 18 09:38:43#+00#TRACE#io.netty.handler.logging.LoggingHandler##xxx#AsyncHttpClient-113-4###ed86a5e0a#na#na#na#na#[id: 0x6b4eed08, L:/10.215.181.236:39394 - R:DEST_HOST/IP:443] READ COMPLETE|

The channel is closed immediately after that

2021 03 18 09:38:43#+00#DEBUG#org.asynchttpclient.netty.handler.HttpHandler##xxx#AsyncHttpClient-113-4###ed86a5e0a#na#na#na#na#Channel Closed: [id: 0x6b4eed08, L:/SOURCE_IP:39394 ! R:DEST_HOST/IP:443] with attribute NettyResponseFuture{currentRetry=0, isDone=0, isCancelled=0, asyncHandler=AhcAsyncHandler for exchangeId: ID-xxxx-1615703537064-62-74 -> https://DEST_HOST/url, nettyRequest=org.asynchttpclient.netty.request.NettyRequest@4c3bd1df, future=java.util.concurrent.CompletableFuture@40ba59d5[Not completed], uri=https://DEST_HOST/url, keepAlive=true, redirectCount=0, timeoutsHolder=org.asynchttpclient.netty.timeout.TimeoutsHolder@685873b5, inAuth=0, touch=1616060323740}|

Recovering for the request B works, but nearly 3 minutes were wasted

2021 03 18 09:38:43#+00#DEBUG#org.asynchttpclient.netty.request.NettyRequestSender##xxx#AsyncHttpClient-113-4###ed86a5e0a#na#na#na#na#Trying to recover request DefaultFullHttpRequest(decodeResult: success, version: HTTP/1.1, content: EmptyByteBufBE)

From my point of view there seems to be miscommunication between Channel Pool and Netty. The channel that is still busy reading should not be added to the pool and used by other requests.

Thanks, Yuri

[YurZir]

Appears that the problem is not related to the chunked HTTP response. The issue seems to be rather related to the fact that subsequent processing of the first request blocked the thread and reuse of an open channel is somehow bound to the Java thread that opened this channel. Not clear why it happens, but decoupling of the subsequent processing from the same thread where the HTTP request was done helps.