You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hc.apache.org by "Sam Berlin (JIRA)" <ji...@apache.org> on 2008/03/15 04:02:24 UTC
[jira] Commented: (HTTPCLIENT-747) No entry created for this pool.
[ https://issues.apache.org/jira/browse/HTTPCLIENT-747?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12578994#action_12578994 ]
Sam Berlin commented on HTTPCLIENT-747:
---------------------------------------
We're still being hit by this in the 'httpclient-4.0-alpha4-20080303.184117-1.jar' snapshot, so I sleuthed around to see what I could dig up.
I added some debugging log-statements into the code and was able to retrigger the bug. This is what printed:
--
1968 DEBUG [PushProxy Requests] http.DefaultHttpExecutor.performRequest - Requesting from: http://one.ip.address.and:port/request-uri
1968 DEBUG [PushProxy Requests] tsccm.RouteSpecificPool.createdEntry - Creating an entry (will be: 1) for route: HttpRoute[{}->http://one.ip.address.and:port], 18818235
3968 DEBUG [PushProxy Requests] http.DefaultHttpExecutor.performRequest - Requesting from: http://one.ip.address.and:port/request-uri
3968 DEBUG [PushProxy Requests] tsccm.RouteSpecificPool.createdEntry - Creating an entry (will be: 2) for route: HttpRoute[{}->http://one.ip.address.and:port], 18818235
6968 DEBUG [PushProxy Requests] http.DefaultHttpExecutor.performRequest - Request finished: http://one.ip.address.and:port/request-uri
8609 DEBUG [PushProxy Requests] http.DefaultHttpExecutor.performRequest - Requesting from: http://one.ip.address.and:port/another-uri
8968 DEBUG [PushProxy Requests] http.DefaultHttpExecutor.performRequest - Request finished: http://one.ip.address.and:port/request-uri
13968 DEBUG [Timer-0] http.DefaultHttpExecutor.shutdown - Aborting request to: http://one.ip.address.and:port/another-uri
33203 DEBUG [RefQueueWorker@org.apache.http.impl.conn.tsccm.ConnPoolByRoute@1e081c5] tsccm.RouteSpecificPool.dropEntry - Dropping an entry (will be: 1) for route: HttpRoute[{}->http://one.ip.address.and:port], 18818235
33203 DEBUG [RefQueueWorker@org.apache.http.impl.conn.tsccm.ConnPoolByRoute@1e081c5] tsccm.RouteSpecificPool.dropEntry - Dropping an entry (will be: 0) for route: HttpRoute[{}->http://one.ip.address.and:port], 18818235
33218 DEBUG [PushProxy Requests] tsccm.RouteSpecificPool.createdEntry - Creating an entry (will be: 1) for route: HttpRoute[{}->http://one.ip.address.and:port], 18818235
33828 DEBUG [PushProxy Requests] tsccm.RouteSpecificPool.freeEntry - Freeing an entry for route: HttpRoute[{}->http://one.ip.address.and:port], 33212367
java.lang.IllegalStateException: No entry created for this pool. HttpRoute[{}->http://one.ip.address.and:port]
at org.apache.http.impl.conn.tsccm.RouteSpecificPool.freeEntry(RouteSpecificPool.java:142)
at org.apache.http.impl.conn.tsccm.ConnPoolByRoute.freeEntry(ConnPoolByRoute.java:337)
at org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager.releaseConnection(ThreadSafeClientConnManager.java:230)
at org.apache.http.impl.client.DefaultClientRequestDirector.execute(DefaultClientRequestDirector.java:427)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:500)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:455)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:421)
at com.limegroup.gnutella.http.DefaultHttpExecutor.performRequest(DefaultHttpExecutor.java:102)
at com.limegroup.gnutella.http.DefaultHttpExecutor.access$0(DefaultHttpExecutor.java:93)
at com.limegroup.gnutella.http.DefaultHttpExecutor$MultiRequestor.run(DefaultHttpExecutor.java:146)
at org.limewire.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1006)
at org.limewire.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:549)
at java.lang.Thread.run(Unknown Source)
33828 DEBUG [PushProxy Requests] http.DefaultHttpExecutor.performRequest - Request finished: http://one.ip.address.and:port/another-uri
--
Keep in that that (for better or worse) every method execution is done with a different instance of HttpClient. Also note that more than 1 thread is named "PushProxy Requests", so don't be confused thinking that's all one thread.
This is what the lines in the logs mean:
DefaultHttpExecutor.performRequest with "Requesting from": HttpClient.execute(HttpUriRequest) is about to be called.
DefaultHttpExecutor.performRequest with "Requested finished": after HttpClient.execute(HttpUriRequest) has returned.
RouteSpecificPool.createdEntry: createdEntry is called with the given route. The "will be" number is what numEntries will increment too. The number at the end after the comma is System.identityHashcode of the RouteSpecificPool object.
DefaultHttpExecutor.shutdown: HttpUriRequest.abort() is about to be called.
RouteSpecificPool.dropEntry: dropEntry is called with the given route. The "will be" is what numEntries will decrement too, and the number after the comma is the identityhashcode of RouteSpecificPool.
RouteSpecificPool.freeEntry: freeEntry is called with the given route. The number after the gonna is the identityhashcode of the RouteSpecificPool.
Things that confuse me:
- Why did it take so long between the 8609 request for 'another-uri' till the 33218 createdEntry? Could a delay in connecting at the socket-level cause this? Are the two entries even related?
- If the request was aborted (at 13968), why did it still try to to create an entry (@ 33218), and what could cause the long delay?
- Why is the identityhashcode for the 33828 freeEntry different from the identityhashcode of every other RouteSpecificPool?
There were connections to other hosts intermingled in the logs, but I stripped those out. If they're useful for debugging, let me know and I can attach the whole thing.
Let me know if there's other things that could be useful, and I'll try to recreate this again. If I can figure out what can cause those log statements to be printed out, I should be able to reproduce this more easily.
> No entry created for this pool.
> -------------------------------
>
> Key: HTTPCLIENT-747
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-747
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpConn
> Affects Versions: 4.0 Alpha 3
> Reporter: Roland Weber
> Priority: Minor
> Fix For: 4.0 Alpha 4
>
>
> Followup to https://issues.apache.org/jira/browse/HTTPCLIENT-741, as reported by Sam Berlin:
> java.lang.IllegalStateException: No entry created for this pool. HttpRoute[{}->http://74.160.66.42:14561]
> at org.apache.http.impl.conn.tsccm.RouteSpecificPool.freeEntry(RouteSpecificPool.java:137)
> at org.apache.http.impl.conn.tsccm.ConnPoolByRoute.freeEntry(ConnPoolByRoute.java:337)
> at org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager.releaseConnection(ThreadSafeClientConnManager.java:230)
> at org.apache.http.impl.client.DefaultClientRequestDirector.execute(DefaultClientRequestDirector.java:427)
> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:500)
> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:455)
> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:421)
> at com.limegroup.gnutella.http.DefaultHttpExecutor.performRequest(DefaultHttpExecutor.java:97)
> at com.limegroup.gnutella.http.DefaultHttpExecutor.access$000(DefaultHttpExecutor.java:26)
> at com.limegroup.gnutella.http.DefaultHttpExecutor$MultiRequestor.run(DefaultHttpExecutor.java:139)
> at org.limewire.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1006)
> at org.limewire.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:549)
> at java.lang.Thread.run(Thread.java:613)
> ---
> DefaultHttpExecutor$MultiRequestor basically is just a Runnable / Cancellable [exposes a cancel() method] that can be cancelled from any thread. cancel just calls abort() on the current AbortableHttpRequest, but is called on a thread other than the one that's doing the client.execute(request).
> The last one is the most common exception, and seems to happen with some regularity. The other two we've only seen once, so may just be a memory quirk (we've seen some crazy bugs, including recursive NPEs while constructing an NPE.)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
For additional commands, e-mail: dev-help@hc.apache.org