Requests piling up on one of the connections while running traffic and PENDING/null observed in the HTTP client dump

[owaiscs001]

Jetty version(s) 11.0.11

Java version/vendor 17.0.4

OS type/version linux

Description

Case 1: While testing my application, I observed Jetty not forwarding the requests on one of the connections and showing PENDING/null in the HTTP client dump attaching the dump for your reference. The requests are piling up on this connection and Jetty is not able to clean the connection context or close the connection and create a new one.

`+= HttpDestination[Origin@9c451e6d[http://10.10.30.40:8080,tag=null,protocol=Protocol@301a9e[proto=[h2c],nego=false]]]@63cd5dab,queue=9,pool=MultiplexConnectionPool@1a0bcf64[c=0/2/2,a=0,i=0,q=9] - STARTED
|  += MultiplexConnectionPool@1a0bcf64[c=0/2/2,a=0,i=0,q=9] - STARTED
|  |  +- @4212de50[inUse=0,size=2,max=2,closed=false]
|  |     +> entries size=2
|  |        +> MultiEntry@75772a59{CLOSED,usage=0,multiplex=99,pooled=HttpConnectionOverHTTP2@7cde1159(closed=true)[HTTP2ClientSession@386a8149{local:null,remote:null,sendWindow=43659,recvWindow=16767912,state=[streams=-99,CLOSED,goAwayRecv=null,goAwaySent=GoAwayFrame@6c5e284a{0/no_error/Idle timeout expired: 600000 ms},failure=org.eclipse.jetty.io.EofException]}]}
|  |        +> MultiEntry@2037e27a{CLOSED,usage=0,multiplex=99,pooled=HttpConnectionOverHTTP2@2cef6bfc(closed=true)[HTTP2ClientSession@4063d7e1{local:null,remote:null,sendWindow=19075,recvWindow=16769570,state=[streams=-99,CLOSED,goAwayRecv=null,goAwaySent=GoAwayFrame@5de2bbdf{0/no_error/Idle timeout expired: 600000 ms},failure=org.eclipse.jetty.io.EofException]}]}
|  +> exchanges size=9
|     +> HttpExchange@4259b62b{req=HttpRequest[POST /testuri HTTP/1.1]@153e8517[PENDING/null] res=HttpResponse[null 0 null]@4bbc948e[PENDING/null]}
|     +> HttpExchange@348f265{req=HttpRequest[POST /testuri HTTP/1.1]@c2ff4c9[PENDING/null] res=HttpResponse[null 0 null]@6d58ce66[PENDING/null]}
|     +> HttpExchange@426f2fa7{req=HttpRequest[POST /testuri HTTP/1.1]@6f03655[PENDING/null] res=HttpResponse[null 0 null]@758a13fe[PENDING/null]}
|     +> HttpExchange@5e8ac8d7{req=HttpRequest[POST /testuri HTTP/1.1]@6523c6b6[PENDING/null] res=HttpResponse[null 0 null]@626606d9[PENDING/null]}
|     +> HttpExchange@4756ec88{req=HttpRequest[POST /testuri HTTP/1.1]@4f9248c5[PENDING/null] res=HttpResponse[null 0 null]@347f31f7[PENDING/null]}
|     +> HttpExchange@66fda96f{req=HttpRequest[POST /testuri HTTP/1.1]@16bf2b94[PENDING/null] res=HttpResponse[null 0 null]@4b368de6[PENDING/null]}
|     +> HttpExchange@60bedfe{req=HttpRequest[POST /testuri HTTP/1.1]@db68a81[PENDING/null] res=HttpResponse[null 0 null]@623ae328[PENDING/null]}
|     +> HttpExchange@1d1c0b34{req=HttpRequest[POST /testuri HTTP/1.1]@44217174[PENDING/null] res=HttpResponse[null 0 null]@7d7a19f3[PENDING/null]}
|     +> HttpExchange@48ec86d7{req=HttpRequest[POST /testuri HTTP/1.1]@35546155[PENDING/null] res=HttpResponse[null 0 null]@7ab10c5a[PENDING/null]}`

Case 2: In other cases it is working for all the IPs and the connections are behaving properly attaching the HTTP client dump for one of the connections (Where it is behaving as expected) also

`SelectionKey@5b4118ef{i=1}->SocketChannelEndPoint@74a75dff[{l=/10.10.37.56:48890,r=/10.10.62.192:8080,OPEN,fill=FI,flush=-,to=61/600000}{io=1/1,kio=1,kro=1}]->[HTTP2ClientConnection@9bbb5c2]

HTTP2ClientSession@47084297{local:/10.10.37.56:48890,remote:/10.10.62.192:8080,sendWindow=43419,recvWindow=16415708,state=[streams=0,NOT_CLOSED,goAwayRecv=null,goAwaySent=null,failure=null]} - STARTED
|     |  +- BufferingFlowControlStrategy@53c9dd54[ratio=0.50,sessionLevel=361508,sessionStallTime=0ms,streamsStallTime=0ms]
|     |  +- HTTP2Flusher@7dd10cf0[IDLE][window_queue=0,frame_queue=0,processed/pending=0/0]
|     |  +> streams size=0
|     += 

+= HttpDestination[Origin@50bc3ffd[http://10.10.62.192:8080,tag=null,protocol=Protocol@301a9e[proto=[h2c],nego=false]]]@680d706f,queue=0,pool=MultiplexConnectionPool@3aa36d3d[c=0/2/2,a=0,i=1,q=0] - STARTED
|  += MultiplexConnectionPool@3aa36d3d[c=0/2/2,a=0,i=1,q=0] - STARTED
|  |  +- @67fdf7a7[inUse=0,size=2,max=2,closed=false]
|  |     +> entries size=2
|  |        +> MultiEntry@302e2fc8{CLOSED,usage=0,multiplex=99,pooled=HttpConnectionOverHTTP2@33a3bfaa(closed=true)[HTTP2ClientSession@1248e666{local:null,remote:null,sendWindow=39187,recvWindow=16766482,state=[streams=-98,CLOSED,goAwayRecv=null,goAwaySent=GoAwayFrame@1a807b47{0/no_error/Idle timeout expired: 600000 ms},failure=org.eclipse.jetty.io.EofException]}]}
|  |        +> MultiEntry@5b1147b0{IDLE,usage=1135942,multiplex=0,pooled=HttpConnectionOverHTTP2@75e1ed97(closed=false)[HTTP2ClientSession@47084297{local:/10.10.37.56:48890,remote:/10.10.62.192:8080,sendWindow=43419,recvWindow=16415708,state=[streams=0,NOT_CLOSED,goAwayRecv=null,goAwaySent=null,failure=null]}]}
|  +> exchanges size=0`

Now, my question is why Jetty is not cleaning the context or closing the connection and creating a new one in case 1.

Also, I have previously raised a ticket in a similar direction and this is the second time I am observing this issue again. Attaching ticket link #9070 for your reference to get more understanding of the issue.

Please let me know if the above HTTP client dump is sufficient for debugging and if not please provide some help on how to debug this issue and what approaches I can try to give you further insights.

I would really appreciate your input, thanks

[joakime]

I would upgrade your version of Java 17 and try again. 17.0.4 has many reported networking issues fixed in later versions. Things should start behaving better with 17.0.5 (or newer).

[sbordet]

@owaiscs001 I think you have network issues.

The first dump (and also the second) show that HttpClient tried to open a connection to the server but failed, and after 10 minutes it idle timed out.

| | +> MultiEntry@75772a59{CLOSED,usage=0,multiplex=99,pooled=HttpConnectionOverHTTP2@7cde1159(closed=true)[HTTP2ClientSession@386a8149{local:null,remote:null,sendWindow=43659,recvWindow=16767912,state=[streams=-99,CLOSED,goAwayRecv=null,goAwaySent=GoAwayFrame@6c5e284a{0/no_error/Idle timeout expired: 600000 ms},failure=org.eclipse.jetty.io.EofException]}]}

See how local:null,remote:null meaning that the TCP socket was not bound locally nor connected to the server.

After 600000 ms (10 minutes), HttpClient idle timed out and sent a GoAwayFrame but did not get a reply.

I think we have an issue: when the network is faulty, like in your case, we do not correctly clean the connection pool.

Having said that, you likely have a faulty network.

Even in the second dump, one connection is faulty (302e2fc8), and the other (5b1147b0) did all the work.

[github-actions[bot]]

This issue has been automatically marked as stale because it has been a full year without activity. It will be closed if no further activity occurs. Thank you for your contributions.

[sbordet]

Closing as answered.