Attaching 2 log snippets.
First is the httpclient log with log4j.logger.org.apache.http=TRACE, F as the
log4j setting. I've included the very last line of the wire trace from the
previous call.. just to give some conetext. I think what you are looking for is
right around: 2010-05-22 16:41:03,411
The second is our client logs, just to show when the call was attempted and
failed with the IllegalStateException.
FYI my idleconnectionhandler is running every 1000ms and evicting anything
older than 20,000ms.
======== httpclient log =========
2010-05-22 16:40:42,864 DEBUG http.wire (Wire.java:78) - << "[EOL]"
2010-05-22 16:40:42,864 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:218) - Released connection is reusable.
2010-05-22 16:40:42,864 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:366)
- Releasing connection
[HttpRoute[{}->http://prf-services.mycompany.net:9810]][null]
2010-05-22 16:40:42,864 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:386)
- Pooling connection
[HttpRoute[{}->http://prf-services.mycompany.net:9810]][null]; keep alive for
-1 MILLISECONDS
2010-05-22 16:40:42,864 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:77) - Adding connection at: 1274560842864
2010-05-22 16:40:42,864 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:619)
- Notifying no-one, there are no waiting threads
2010-05-22 16:40:43,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:43,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560843270
2010-05-22 16:40:43,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:43,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560823270
2010-05-22 16:40:44,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:44,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560844270
2010-05-22 16:40:44,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:44,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560824270
2010-05-22 16:40:45,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:45,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560845270
2010-05-22 16:40:45,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:45,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560825270
2010-05-22 16:40:46,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:46,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560846270
2010-05-22 16:40:46,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:46,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560826270
2010-05-22 16:40:47,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:47,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560847270
2010-05-22 16:40:47,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:47,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560827270
2010-05-22 16:40:48,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:48,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560848270
2010-05-22 16:40:48,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:48,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560828270
2010-05-22 16:40:49,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:49,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560849270
2010-05-22 16:40:49,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:49,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560829270
2010-05-22 16:40:50,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:50,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560850270
2010-05-22 16:40:50,270 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:50,270 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560830270
2010-05-22 16:40:51,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:51,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560851395
2010-05-22 16:40:51,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:51,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560831395
2010-05-22 16:40:52,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:52,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560852395
2010-05-22 16:40:52,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:52,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560832395
2010-05-22 16:40:53,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:53,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560853395
2010-05-22 16:40:53,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:53,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560833395
2010-05-22 16:40:54,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:54,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560854395
2010-05-22 16:40:54,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:54,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560834395
2010-05-22 16:40:55,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:55,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560855395
2010-05-22 16:40:55,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:55,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560835395
2010-05-22 16:40:56,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:56,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560856395
2010-05-22 16:40:56,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:56,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560836395
2010-05-22 16:40:57,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:57,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560857395
2010-05-22 16:40:57,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:57,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560837395
2010-05-22 16:40:58,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:58,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560858395
2010-05-22 16:40:58,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:58,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560838395
2010-05-22 16:40:59,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:40:59,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560859395
2010-05-22 16:40:59,395 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:40:59,395 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560839395
2010-05-22 16:41:00,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:00,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560860396
2010-05-22 16:41:00,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:00,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560840396
2010-05-22 16:41:01,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:01,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560861396
2010-05-22 16:41:01,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:01,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560841396
2010-05-22 16:41:02,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:02,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560862396
2010-05-22 16:41:02,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:02,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560842396
2010-05-22 16:41:03,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:03,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560863396
2010-05-22 16:41:03,396 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:03,396 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560843396
2010-05-22 16:41:03,411 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:168) -
ThreadSafeClientConnManager.getConnection:
HttpRoute[{}->http://prf-services.mycompany.net:9810], timeout = 0
2010-05-22 16:41:03,411 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:129) - Closing idle connection, connection time:
1274560842864
2010-05-22 16:41:03,411 DEBUG conn.DefaultClientConnection
(DefaultClientConnection.java:153) - Connection closed
2010-05-22 16:41:03,411 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:281)
- Total connections kept alive: 1
2010-05-22 16:41:03,411 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:282)
- Total issued connections: 0
2010-05-22 16:41:03,411 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:283)
- Total allocated connection: 1 out of 5
2010-05-22 16:41:03,411 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:428)
- Getting free connection
[HttpRoute[{}->http://prf-services.mycompany.net:9810]][null]
2010-05-22 16:41:03,411 DEBUG conn.DefaultClientConnection
(DefaultClientConnection.java:141) - Connection shut down
2010-05-22 16:41:03,411 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:220) - Released connection is not reusable.
2010-05-22 16:41:03,411 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:366)
- Releasing connection
[HttpRoute[{}->http://prf-services.mycompany.net:9810]][null]
2010-05-22 16:41:03,411 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:619)
- Notifying no-one, there are no waiting threads
2010-05-22 16:41:04,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:04,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560864427
2010-05-22 16:41:04,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:04,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560844427
2010-05-22 16:41:05,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:05,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560865427
2010-05-22 16:41:05,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:05,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560845427
2010-05-22 16:41:06,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:06,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560866427
2010-05-22 16:41:06,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:06,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560846427
2010-05-22 16:41:07,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:07,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560867427
2010-05-22 16:41:07,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:07,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560847427
2010-05-22 16:41:08,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:08,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560868427
2010-05-22 16:41:08,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:08,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560848427
2010-05-22 16:41:09,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:09,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560869427
2010-05-22 16:41:09,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:09,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560849427
2010-05-22 16:41:10,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:10,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560870427
2010-05-22 16:41:10,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:10,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560850427
2010-05-22 16:41:11,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:11,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560871427
2010-05-22 16:41:11,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:11,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560851427
2010-05-22 16:41:12,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:12,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560872427
2010-05-22 16:41:12,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:12,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560852427
2010-05-22 16:41:13,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:13,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560873427
2010-05-22 16:41:13,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:13,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560853427
2010-05-22 16:41:14,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:14,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560874427
2010-05-22 16:41:14,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:14,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560854427
2010-05-22 16:41:15,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:15,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560875427
2010-05-22 16:41:15,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:15,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560855427
2010-05-22 16:41:16,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:16,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560876427
2010-05-22 16:41:16,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:16,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560856427
2010-05-22 16:41:17,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:17,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560877427
2010-05-22 16:41:17,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:17,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560857427
2010-05-22 16:41:18,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:18,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560878427
2010-05-22 16:41:18,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:18,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560858427
2010-05-22 16:41:19,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:19,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560879427
2010-05-22 16:41:19,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:19,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560859427
2010-05-22 16:41:20,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:20,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560880427
2010-05-22 16:41:20,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:20,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560860427
2010-05-22 16:41:21,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:21,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560881427
2010-05-22 16:41:21,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:21,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560861427
2010-05-22 16:41:22,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:274) - Closing expired connections
2010-05-22 16:41:22,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:144) - Checking for expired connections, now:
1274560882427
2010-05-22 16:41:22,427 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:267) - Closing connections idle for 20000
MILLISECONDS
2010-05-22 16:41:22,427 DEBUG conn.IdleConnectionHandler
(IdleConnectionHandler.java:119) - Checking for connections, idle timeout:
1274560862427
2010-05-22 16:41:22,568 DEBUG tsccm.ThreadSafeClientConnManager
(ThreadSafeClientConnManager.java:168) -
ThreadSafeClientConnManager.getConnection:
HttpRoute[{}->http://prf-services.mycompany.net:9810], timeout = 0
2010-05-22 16:41:22,568 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:281)
- Total connections kept alive: 0
2010-05-22 16:41:22,568 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:282)
- Total issued connections: 0
2010-05-22 16:41:22,568 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:283)
- Total allocated connection: 0 out of 5
2010-05-22 16:41:22,568 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:454)
- No free connections
[HttpRoute[{}->http://prf-services.mycompany.net:9810]][null]
2010-05-22 16:41:22,568 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:300)
- Available capacity: 5 out of 5
[HttpRoute[{}->http://prf-services.mycompany.net:9810]][null]
2010-05-22 16:41:22,568 DEBUG tsccm.ConnPoolByRoute (ConnPoolByRoute.java:481)
- Creating new connection
[HttpRoute[{}->http://prf-services.mycompany.net:9810]]
2010-05-22 16:41:22,568 DEBUG client.DefaultHttpClient
(DefaultRequestDirector.java:481) - Attempt 1 to execute request
2010-05-22 16:41:22,568 DEBUG conn.DefaultClientConnection
(DefaultClientConnection.java:244) - Sending request: POST
/cms.rcts/2010.2.1R3/ccs/prf.lr/default/cdc/essd-remote/ HTTP/1.1
2010-05-22 16:41:22,568 DEBUG http.wire (Wire.java:78) - >> "POST
/cms.rcts/2010.2.1R3/ccs/prf.lr/default/cdc/essd-remote/ HTTP/1.1[EOL]"
======= our client log ========
22-May-2010:16:41:03.396 scd2ntb216 main INFO
IRetentionCasesService.createAuditInfo() NA Created
correlation id[ltu068_scd2ntb216_-188e9680:128bb650277:-6e6d] for
mChannel=test;mUserId=ltu068;mParentAuditId=null;correlationId=null;operatorId=null
22-May-2010:16:41:03.427 scd2ntb216 main EXCEPTION
IRetentionCasesService.getIncentiveSequence
ltu068_scd2ntb216_-188e9680:128bb650277:-6e6d SYSTEM_EXCEPTION[Error making
call[Error executing Remote Method=[getIncentiveSequence] for Service
Url=[http://prf-services.mycompany.net:9810/cms.rcts/2010.2.1R3/ccs/prf.lr/default/cdc]
Exception=[java.lang.IllegalStateException: Connection already open.
at
org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:135)
at
org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:108)
at
org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:641)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:576)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:554)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceExecutorImpl.executeWithConnectionTimeoutRetries(RemoteServiceExecutorImpl.java:159)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceExecutorImpl.executeRequest(RemoteServiceExecutorImpl.java:126)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceProxy.invoke(RemoteServiceProxy.java:50)
at $Proxy2.getIncentiveSequence(Unknown Source)
at
com.ccs.cco.cms.rcts.client.cases.RetentionCasesRemotingDelegate.getIncentiveSequence(RetentionCasesRemotingDelegate.java:748)
at Actions.action(Actions.java:2887)
]]]
com.fusa.ssg.SystemException: Error making call[Error executing Remote
Method=[getIncentiveSequence] for Service
Url=[http://prf-services.mycompany.net:9810/cms.rcts/2010.2.1R3/ccs/prf.lr/default/cdc]
Exception=[java.lang.IllegalStateException: Connection already open.
at
org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:135)
at
org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:108)
at
org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:641)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:576)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:554)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceExecutorImpl.executeWithConnectionTimeoutRetries(RemoteServiceExecutorImpl.java:159)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceExecutorImpl.executeRequest(RemoteServiceExecutorImpl.java:126)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceProxy.invoke(RemoteServiceProxy.java:50)
at $Proxy2.getIncentiveSequence(Unknown Source)
at
com.ccs.cco.cms.rcts.client.cases.RetentionCasesRemotingDelegate.getIncentiveSequence(RetentionCasesRemotingDelegate.java:748)
at Actions.action(Actions.java:2887)
]]
at
com.ccs.cco.cms.rcts.client.cases.RetentionCasesRemotingDelegate.getIncentiveSequence(RetentionCasesRemotingDelegate.java:763)
at Actions.action(Actions.java:2887)
------------Wrapped Exception-----------
com.fusa.ssg.infra.remoting.common.RemoteServiceException: Error executing
Remote Method=[getIncentiveSequence] for Service
Url=[http://prf-services.mycompany.net:9810/cms.rcts/2010.2.1R3/ccs/prf.lr/default/cdc]
Exception=[java.lang.IllegalStateException: Connection already open.
at
org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:135)
at
org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:108)
at
org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:641)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:576)
at
org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:554)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceExecutorImpl.executeWithConnectionTimeoutRetries(RemoteServiceExecutorImpl.java:159)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceExecutorImpl.executeRequest(RemoteServiceExecutorImpl.java:126)
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceProxy.invoke(RemoteServiceProxy.java:50)
at $Proxy2.getIncentiveSequence(Unknown Source)
at
com.ccs.cco.cms.rcts.client.cases.RetentionCasesRemotingDelegate.getIncentiveSequence(RetentionCasesRemotingDelegate.java:748)
at Actions.action(Actions.java:2887)
]
at
com.fusa.ssg.infra.remoting.client.service.RemoteServiceProxy.invoke(RemoteServiceProxy.java:53)
at $Proxy2.getIncentiveSequence(Unknown Source)
at
com.ccs.cco.cms.rcts.client.cases.RetentionCasesRemotingDelegate.getIncentiveSequence(RetentionCasesRemotingDelegate.java:748)
at Actions.action(Actions.java:2887)
22-May-2010:16:41:03.427 scd2ntb216 main PERFORMANCEMONITOR
IRetentionCasesService.getIncentiveSequence ClientId=test_2010.2.1R3
getIncentiveSequence call. ltu068_scd2ntb216_-188e9680:128bb650277:-6e6d 31
-----Original Message-----
From: Oleg Kalnichevski [mailto:[email protected]]
Sent: Wednesday, May 26, 2010 4:55 AM
To: HttpClient User Discussion
Subject: RE: java.lang.IllegalStateException: Connection already open
On Tue, 2010-05-25 at 16:31 -0400, Brooks, Kenneth S wrote:
> Oleg,
>
> 22-May-2010:07:56:19.310 scd2ntb215 main EXCEPTION
> AbunchOfOurInfo... ltu068_scd2ntb215_-1c64b48c:128bb71b989:-73d0
> SYSTEM_EXCEPTION[Error making call[Error executing Remote
> Method=[addIncentive] for Service Url=[http://mymachine:9810/myurl]
> Exception=[java.lang.IllegalStateException: Connection already open.
> at
> org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:135)
> at
> org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:108)
> at
> org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:641)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:576)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:554)
> ....our code here
> ]]]
> com.mycompany.SystemException: Error making call[Error executing Remote
> Method=[addIncentive] for Service Url=[ http://mymachine:9810/myurl]
> Exception=[java.lang.IllegalStateException: Connection already open.
> at
> org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:135)
> at
> org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:108)
> at
> org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:641)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:576)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:554)
> ....our code here
> ------------Wrapped Exception-----------
> com.mycompany.RemoteServiceException: Error executing Remote
> Method=[addIncentive] for Service Url=[ http://mymachine:9810/myurl]
> Exception=[java.lang.IllegalStateException: Connection already open.
> at
> org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:135)
> at
> org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:108)
> at
> org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:641)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:576)
> at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:554)
> ....our code here
>
> Can't reproduce it right now because we only saw it a couple of times (during
> a performance test).
> I do have wire traces on, didn't see anything in there..
> But I don't think I have context logging for connection management / request
> execution turned on.
> I'll see if I can get those on for the next test.
>
> -ken
Hi Ken
There is likely to be a race condition in the AbstractPoolEntry class,
triggered by a combination of the IdleConnectionMonitorThread and heavy
load. I will be trying to pinpoint it. A connection management / request
execution context log would be very helpful, though.
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
This transmission may contain information that is privileged,
confidential, legally privileged, and/or exempt from disclosure
under applicable law. If you are not the intended recipient, you
are hereby notified that any disclosure, copying, distribution, or
use of the information contained herein (including any reliance
thereon) is STRICTLY PROHIBITED. Although this transmission and
any attachments are believed to be free of any virus or other
defect that might affect any computer system into which it is
received and opened, it is the responsibility of the recipient to
ensure that it is virus free and no responsibility is accepted by
JPMorgan Chase & Co., its subsidiaries and affiliates, as
applicable, for any loss or damage arising in any way from its use.
If you received this transmission in error, please immediately
contact the sender and destroy the material in its entirety,
whether in electronic or hard copy format. Thank you.
