Bugzilla – Full Text Bug Listing
| Summary: | HttpConnection "wait" call causes thread resource exhaustion | ||
|---|---|---|---|
| Product: | [RT] Jetty | Reporter: | Keith Skinner <keith.skinner> |
| Component: | client | Assignee: | Jan Bartel <janb> |
| Status: | RESOLVED FIXED | QA Contact: | |
| Severity: | major | ||
| Priority: | P3 | CC: | geoff, janb, jesse.mcconnell, jetty-inbox |
| Version: | 8.0.4 | ||
| Target Milestone: | 7.5.x | ||
| Hardware: | Other | ||
| OS: | Linux | ||
| Whiteboard: | |||
Keith, This situation isn't resolved by using the various timeouts already able to be configured on both the HttpClient or the HttpExchange? Also are you using the async ProxyServlet we have in the jetty-servlets package? Jesse, > This situation isn't resolved by using the various timeouts already able to be > configured on both the HttpClient or the HttpExchange? No. These time-outs do occur and have no effect on the problem. Once the code arrives at the wait() call, it does not (can not) exit from that blocked state unless a notify() call is made, and this will only occur when there is a subsequent exchange object for the HttpConnection to service (the line 129 reference). > Also are you using the async ProxyServlet we have in the jetty-servlets > package? Yes, we are using/extending the org.eclipse.jetty.servlets.ProxyServlet class (along with some local modifications to the jetty client classes -- we have tried to modify as little as possible to satisfy our needs). Greg, instead of my addressing this in master which will probably not see the light of day given the 7.6 branch work you have coming in with changes to this section of code...does for your new setup cover this case? Keith, There have been significant changes to the IO layer for both jetty server and client code in the 7.6.x releases. It would be great if you could try out the latest RC release (at time of writing, that is RC3, with RC4 due out shortly). If the same thing happens with 7.6.x, then a thread dump would be useful. I also think it would be worthwhile your switching to the SelectConnector and do async-style connections if the network is slow. regards Jan Jan,
Unfortunately, the problem still exists in the 7.6.0.RC4 release. The
class HttpConnection no longer exists: the code has been moved/renamed
into class BlockingHttpConnection, which still exhibits the same
failing pattern. The problem is that should the code descend into the
wait() call on line 74:
synchronized (this)
{
exchange=_exchange;
while (exchange == null)
{
try
{
this.wait();
exchange=_exchange;
}
catch (InterruptedException e)
{
throw new InterruptedIOException();
}
}
}
this code will wait forever until an HTTP exchange object is provided
for it to service on this connection (via the notifyAll() in the
send() method call). We are seeing that eventually all usable threads
in the thread pool enter this condition (note: AsyncProxyServlet is
our extension of org.eclipse.jetty.servlets.ProxyServlet, and line
numbers may not match the RC4 release due to added diagnostics):
AsyncProxyServlet-1968604756-155[1] where
[1] java.lang.Object.wait (native method)
[2] java.lang.Object.wait (Object.java:502)
[3] org.eclipse.jetty.client.BlockingHttpConnection.handle (BlockingHttpConnection.java:81)
[4] org.eclipse.jetty.client.SocketConnector$1.run (SocketConnector.java:100)
[5] org.eclipse.jetty.util.thread.QueuedThreadPool.runJob (QueuedThreadPool.java:599)
[6] org.eclipse.jetty.util.thread.QueuedThreadPool$3.run (QueuedThreadPool.java:534)
[7] java.lang.Thread.run (Thread.java:679)
AsyncProxyServlet-1968604756-155[1] up 2
AsyncProxyServlet-1968604756-155[3] dump this
this = {
LOG: instance of org.eclipse.jetty.util.log.StdErrLog(id=2275)
_requestComplete: false
_requestContentChunk: null
org.eclipse.jetty.client.AbstractHttpConnection.LOG: instance of org.eclipse.jetty.util.log.StdErrLog(id=2276)
org.eclipse.jetty.client.AbstractHttpConnection._destination: instance of org.eclipse.jetty.client.HttpDestination(id=2277)
org.eclipse.jetty.client.AbstractHttpConnection._generator: instance of org.eclipse.jetty.http.HttpGenerator(id=2278)
org.eclipse.jetty.client.AbstractHttpConnection._parser: instance of org.eclipse.jetty.http.HttpParser(id=2279)
org.eclipse.jetty.client.AbstractHttpConnection._http11: true
org.eclipse.jetty.client.AbstractHttpConnection._status: 200
org.eclipse.jetty.client.AbstractHttpConnection._connectionHeader: null
org.eclipse.jetty.client.AbstractHttpConnection._reserved: false
org.eclipse.jetty.client.AbstractHttpConnection._exchange: null
org.eclipse.jetty.client.AbstractHttpConnection._pipeline: null
org.eclipse.jetty.client.AbstractHttpConnection._idleTimeout: instance of org.eclipse.jetty.client.AbstractHttpConnection$ConnectionIdleTask(id=2280)
org.eclipse.jetty.client.AbstractHttpConnection._idle: instance of java.util.concurrent.atomic.AtomicBoolean(id=2281)
org.eclipse.jetty.io.AbstractConnection.LOG: instance of org.eclipse.jetty.util.log.StdErrLog(id=2282)
org.eclipse.jetty.io.AbstractConnection._timeStamp: 1327082570931
org.eclipse.jetty.io.AbstractConnection._endp: instance of org.eclipse.jetty.io.bio.SocketEndPoint(id=2283)
}
AsyncProxyServlet-1968604756-155[3] dump _destination
_destination = {
LOG: instance of org.eclipse.jetty.util.log.StdErrLog(id=2284)
_queue: instance of java.util.LinkedList(id=2285)
_connections: instance of java.util.LinkedList(id=2286)
_newQueue: instance of java.util.concurrent.ArrayBlockingQueue(id=2287)
_idle: instance of java.util.ArrayList(id=2288)
_client: instance of AsyncProxyServlet$CMHttpClient(id=2289)
_address: instance of org.eclipse.jetty.client.Address(id=2290)
_ssl: false
_hostHeader: instance of org.eclipse.jetty.io.ByteArrayBuffer(id=2291)
_maxConnections: 2147483647
_maxQueueSize: 2147483647
_pendingConnections: 0
_newConnection: 0
_proxy: null
_proxyAuthentication: null
_authorizations: null
_cookies: null
}
AsyncProxyServlet-1968604756-155[3] dump _destination._connections
_destination._connections = {
header: instance of java.util.LinkedList$Entry(id=2292)
size: 0
serialVersionUID: 876323262645176354
java.util.AbstractList.modCount: 40
}
AsyncProxyServlet-1968604756-155[3] ^[[A^U
AsyncProxyServlet-1968604756-155[3]
AsyncProxyServlet-1968604756-155[3] dump _destination._idle
_destination._idle = {
serialVersionUID: 8683452581122892189
elementData: instance of java.lang.Object[10] (id=2293)
size: 0
java.util.AbstractList.modCount: 46
}
Note that in this case, the attendant HttpDestination object carries
no reference to this connection in either the master list of all
connections or the list of idle connections (both are empty). The
connection is never goiong to see another exchange object to handle.
This is because the HttpDestination's returnIdleConnection() method
has been called on this object, from the trace:
at org.eclipse.jetty.client.HttpDestination.returnIdleConnection(HttpDestination.java:452)
at org.eclipse.jetty.client.AbstractHttpConnection$ConnectionIdleTask.expired(AbstractHttpConnection.java:484)
at org.eclipse.jetty.util.thread.Timeout.tick(Timeout.java:135)
at org.eclipse.jetty.util.thread.Timeout.tick(Timeout.java:148)
at org.eclipse.jetty.client.HttpClient$1.run(HttpClient.java:434)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
at java.lang.Thread.run(Thread.java:679)
which calls AbstractConnection's onIdleExpired() method to close the
underlying connection, but does nothing to resolve the thread blocked
in the wait call. I have modified BlockingHttpConnection to override
the onIdleExpired method to provide notification to the waiting thread:
@Override
public void onIdleExpired(long idleForMs)
{
super.onIdleExpired (idleForMs);
synchronized (this) {
notifyAll();
}
}
and then modified the handle() method to re-write the wait() logic as
follows:
synchronized (this)
{
while (_exchange == null)
{
try
{
this.wait();
// Can we still do anything with this connection? If not, bail.
if (_endp.isOutputShutdown())
return null;
}
catch (InterruptedException e)
{
throw new InterruptedIOException();
}
}
exchange=_exchange;
}
and this seems to mitigate the resource exhaustion problem.
Actually, the last bit of modified code should read:
synchronized (this)
{
while (_exchange == null)
{
try
{
this.wait();
// Can we still do anything with this connection? If not, bail.
if (_endp.isOutputShutdown())
return this;
}
catch (InterruptedException e)
{
throw new InterruptedIOException();
}
}
exchange=_exchange;
}
as returning a null causes a null-pointer exception in the SocketConnector
code that calls the handle() method.
Cheers!
-Keith
RC5 is on its way into maven central right now, probably be there in an hour or two There's no point in my testing RC5: the source code for the classes in question are identical. I would prefer to spend my time testing something that has a reasonable chance of actually fixing the problem I reported. *** Bug 393876 has been marked as a duplicate of this bug. *** Fixed for jetty 7.6.9 and 8.1.9 Thanks to test case from https://bugs.eclipse.org/bugs/show_bug.cgi?id=393876 we were able to isolate the issue and fix. I should point out however that users should upgrade to jetty-9 as soon as they are able, as the io layer, including the http-client has been extensively reworked and tested. regards Jan Closing after fixing. |
We are running the Jetty client code in a proxy context and have determined that the code eventually deadlocks through resource exhaustion (in this context, the proxy service is making use of network services that can frequently impose significant delays in the responses to the HTTP requests). Specifically, the "wait" call (line 182 of class HttpConnection in version 8.0.4): if (_endp.isBlocking()) { try { this.wait(); } catch (InterruptedException e) { throw new InterruptedIOException(); } } This wait must be the recipient of a notify() call (from exactly one place, on line 129). We have observed the condition that all available threads in the thread pool can be blocked in this wait call and no further requests will be honored by the Jetty code (all such requests being queued up behind the blocked threads). We have devised a work-around by replacing the above code with the following: if (_endp.isBlocking()) { try { this.wait(60000); if (_exchange == null) { close(); return this; } } catch (InterruptedException e) { throw new InterruptedIOException(); } } It is not clear if the "wait-forever" condition is merely a symptom of a failure elsewhere in handling the exchange objects. The one-minute wait time used is arbitrary.