Intermittent connection issues. Jetty 9.4.6.v20170531

[jamesbognar]

There appears to be an intermittent connection issue when using Jetty where socket connections made from Apache HttpClient 4.5.3 simply time out. I cannot figure out if the problem is with Jetty or HttpClient.

I have a test setup that's simply making 100k single-threaded GET requests against a servlet running in Jetty in the same JVM as HttpClient. It's able to process around 1000 requests per second, but a connection appears to hang randomly maybe 5 or 6 time in a million. I tried increasing the thread pool size in Jetty but that didn't appear to fix the issue.

I made a copy of the stack traces at the point of one of these hang events. I was hoping someone could see if it's some sort of deadlock issue in Jetty or tell me if Jetty is even processing a request when the hang occurs.

trace.txt

Here's where it's stuck on the client side...
"main" #1 prio=5 os_prio=31 tid=0x00007fd07e807800 nid=0x1c03 runnable [0x000070000cfc8000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at org.apache.http.impl.conn.LoggingInputStream.read(LoggingInputStream.java:84)

In Jetty, it seems to be stuck here...
"qtp1766145591-22-acceptor-0@660acfb-ServerConnector@3cc1435c{HTTP/1.1,[http/1.1]}{0.0.0.0:10001}" #22 prio=3 os_prio=31 tid=0x00007fd07f89c000 nid=0x6903 runnable [0x000070000ec1e000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
- locked <0x00000006c10eb490> (a java.lang.Object)
at org.eclipse.jetty.server.ServerConnector.accept(ServerConnector.java:352)
at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:603)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591)
at java.lang.Thread.run(Thread.java:745)

Jetty 9.4.6.v20170531
Apache HttpClient 4.5.3
Java HotSpot(TM) 64-Bit Server VM (build 25.77-b03, mixed mode)
Mac OS

[sbordet]

I have a test setup that's simply making 100k single-threaded GET requests against a servlet running in Jetty in the same JVM as HttpClient.

Such setup will open just one connection. If you can get the first request by, then all the others will follow, unless Apache's HttpClient does some weird things with connection management.

The stack trace you posted for Jetty is normal and shows that Jetty is waiting for new connections to be accepted.

You want to take a server dump as explained here when the problem happens.

The client stack trace shows that the client is waiting to read something from the server, so the server dump will tell us in what state is the server - whether it's waiting for more data from the client, etc.

If you have a reproducible test case that you can attach to this issue, will be great.

[jamesbognar]

Thanks for the info! I'll try to narrow the testcase further and generate the server dump. I'll let you know soon.

[jamesbognar]

I'm chalking this up to a VPN issue. If I'm not on a VPN, I'm able to successfully execute 10M REST requests spread out over 10 threads. I only see an issue if I'm connected to my company's VPN.

Here's the dump file generated during a hang. It looks to me that Jetty is still waiting for an incoming connection when it occurs. Can you confirm?

dump.txt

If so, we can close this as a "hardware" issue.

p.s. The dump feature is awesome.

[joakime]

Closing at request of OP

[sbordet]

The dump shows that you have only one connection:

 |   |   |   +- SelectionKey@d16c66e{i=1}->SocketChannelEndPoint@2f1c3bf8{/10.33.32.62:65167<->/10.33.32.62:10001,OPEN,fill=FI,flush=-,to=10008/30000}{io=1/1,kio=1,kro=1}->HttpConnection@6fca731[p=HttpParser{s=START,0 of -1},g=HttpGenerator@3978ff8e{s=START}]=>HttpChannelOverHttp@2e390723{r=783883,c=false,a=IDLE,uri=null}

From that line, we can see that it's open, interested in reading and that the parser and the generator are in start state, which means that the connection is waiting for the next request.
So Jetty is not waiting for an incoming connection, it's waiting for an incoming request on that existing connection.