Diagnosing connection leak problems in WebSphere Application Server V5.0 and V5.1
 Technote (troubleshooting)
 
Problem(Abstract)
The application has become unresponsive; in your SystemOut.log you might see several messages that resemble the following:

WTRN0006W: Transaction 57415344:000000000000832c00000002f028d1f345325019dba7e566018e1
bfe40dcd57073657276657231 has timed out after 120 seconds.

J2CA0045E: Connection not available while invoking method queueRequest for resource
jdbc/InterfaceMonitor

J2CA0020E: The Connection Pool Manager could not allocate a Managed Connection: com.ibm.websphere.ce.j2c.ConnectionWaitTimeoutException: Connection not available, Timed out waiting for 74
 
Cause
Applications that connect to a back-end server and that have become slow or unresponsive might be encountering connection problems that are related to the application code or configuration problems, rather than to bugs in the IBM® WebSphere® Application Server connection manager. These issues include leaked connections that are not explicitly closed by application, and connectionWaitTimeoutExceptions in the application that might fill up the connection pool without returning connections to the free pool.
 
Resolving the problem
The Connection Manager code for WebSphere Application Server versions 5.1.1.3 and 5.0.2.10 and above provides the new diagnostic feature, connection leak trace logic, that gathers information on which application methods might be generating leaked connections, or might be holding on to connections for longer than expected. This information is useful, especially considering that connections should not take much longer then the maximum processing time of the longest running query in the application.

The connection leak trace logic feature is configurable through the property timeInUseLimit which has been defaulted to 10 seconds. This property defines the time interval for checking how long a connection has been in use. The information is output to trace by setting the trace specification to WAS.j2c=all=enabled in the Diagnostic Trace panel in the WebSphere administrative console (method A). This can also be output using wsadmin commands (method B).

When a connection is leaked, or taking longer than 10 secs or taking longer than the specific time configured in this property (which should be set according to the longest running transaction in the application), the trace shows a string Connection Leak Logic Information followed by a stack with all methods involved up to the getConnection( ) which will include the application method that requested the connection.

Note: For WebSphere Application Server versions 5.1.0.3 through 5.1.1.2, the connection leak trace logic is available through the installation of a patch that adds it to the underlying Connection manager code. Also, the property timeInUseLimit needs to be added to the j2c.properties file. The patch and installation instructions can be downloaded from links provided at the bottom of this technote.

Method A
Instructions for enabling connection leak trace logic from the administrative console

  1. If running WebSphere Application Server versions 5.1.1.3 or 5.0.2.10 and above, then the j2c.properties file already has the timeInUseLimit property configured to 10 secs. If running any of the versions from 5.1.0.3 to 5.1.1.2, then replace the j2c.properties file in the %WAS_HOME%\properties directory with the one provided at the bottom of this technote; this file includes text for the timeInUseLimit property or you can also edit your existing j2c.properties file to include the required text for the timeInUseLimit property.

  2. Open the j2c.properties file and change the line below to the desired value in seconds:

    <timeInUseLimit>-1</timeInUseLimit>

    Change the value back to -1 to disable connection leak trace logic.

  3. In the administrative console, expand Troubleshooting, then select Logs and Trace.

  4. Select your server, then select Diagnostic Trace.

  5. Ensure that Enable trace with the following specification is checked.

  6. In the Trace Specification field, type:

    WAS.j2c=all=enabled

  7. Under Trace Output select File, and set Maximum File Size to 100MB and Maximum Number of Historical Files to 20. These values can be modified to better suit file system limitations but making sure that no traces are overwritten is important to study the conditions from startup that may have produced the connection leak.

  8. Click OK, save your configuration, and restart WebSphere Application server so tracing will begin.

  9. Let the application run and start monitoring the trace. If you see string Connection Leak Logic Information in the trace, there are connections that have been in use for more than the time configured in the timeInUseLimit property. Analyze the resulting connection stack for the application methods involved. (see Method A Trace Sample below)

  10. After you are done with analysis, reverse the process to disable your tracing. If you disable tracing, large files do not continue to build in your logs.

Method B
Instructions for enabling connection leak trace logic using wsadmin

  1. Repeat steps 1 and 2 from Method A.

  2. Start wsadmin (%WAS_HOME%\bin\wsadmin).

  3. Use $AdminControl queryNames *:type=DataSource*, or $AdminControl queryNames *:type=J2CConnectionFactory*, to display the object names.

  4. Select the object name of the data source or connection factory of interest. For example: Default_CF ("WebSphere:name=Default_CF..."))

  5. Use set objectName [$AdminControl queryNames *:name=Default_CF,*].

  6. Run the application. Make connections to your back-end server.

  7. After the expected timeInUseLimit passes, start monitoring the pool of connections using $AdminControl invoke $objectName getPoolContents. Look at Method B wsadmin output sample information below for an example of what you might see.

  8. If Connection Leak Logic Information is part of the output, you have connections that are in use for more than the time expected. Analyze the resulting connection stacks for the application methods involved.


Examples using Tracing and wsadmin

In the following sample outputs for Methods A and B, the SnoopServlet.doGet on line 130 requested a connection and has not closed and committed changes for this connection. (For the wsadmin example, this is SnoopServletTest.startTest1 on line 62.)

For this example, the j2c.properties file is set with timeInUseLimit of 20 seconds.

  1. Start time in use
    The first time the connection was allocated.

  2. Time in use
    The amount of time connection has been allocated and in use.

  3. Last allocation time (shared connections only)
    For shared connections, multiple getConnections can occur. This value indicates the last time a getConnection occurred.

  4. Thread Id
    The getConnection request's thread id.

  5. Thread Name
    The getConnection request's thread name.


Method A
Trace sample
(with application method leaking connections in bold)

Connection Leak Logic Information:
 MCWrapper id 16089ef2  Managed connection com.ibm.ws.rsadapter.spi.WSRdbManagedConnectionImpl@6e909ef2  State:STATE_ACTIVE_INUSE Thread Id: 15861ecd Thread Name: Servlet.Engine.Transports : 1
    Start time inuse Wed Nov 03 08:04:54 CST 2004 Time inuse 20 (seconds)
    Last allocation time Wed Nov 03 08:04:54 CST 2004
      getConnection stack trace information:

  at com.ibm.ejs.j2c.ConnectionManager.allocateConnection(ConnectionManager.java:565)
 at com.ibm.ws.rsadapter.jdbc.WSJdbcDataSource.getConnection(WSJdbcDataSource.java:215)
 at com.ibm.ws.rsadapter.jdbc.WSJdbcDataSource.getConnection(WSJdbcDataSource.java:306)
 at
SnoopServlet.doGet(SnoopServlet.java:130)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
 at com.ibm.ws.webcontainer.servlet.StrictServletInstance.doService(StrictServletInstance.java:110)
 at com.ibm.ws.webcontainer.servlet.StrictLifecycleServlet._service(StrictLifecycleServlet.java:174)
 at com.ibm.ws.webcontainer.servlet.IdleServletState.service(StrictLifecycleServlet.java:313)
 at com.ibm.ws.webcontainer.servlet.StrictLifecycleServlet.service(StrictLifecycleServlet.java:116)
 at com.ibm.ws.webcontainer.servlet.ServletInstance.service(ServletInstance.java:283)
 at com.ibm.ws.webcontainer.servlet.ValidServletReferenceState.dispatch(ValidServletReferenceState.java:42)
 at com.ibm.ws.webcontainer.servlet.ServletInstanceReference.dispatch(ServletInstanceReference.java:40)
 at com.ibm.ws.webcontainer.webapp.WebAppRequestDispatcher.handleWebAppDispatch(WebAppRequestDispatcher.java:1059)
 at com.ibm.ws.webcontainer.webapp.WebAppRequestDispatcher.dispatch(WebAppRequestDispatcher.java:588)
 at com.ibm.ws.webcontainer.webapp.WebAppRequestDispatcher.forward(WebAppRequestDispatcher.java:206)
 at com.ibm.ws.webcontainer.srt.WebAppInvoker.doForward(WebAppInvoker.java:80)
 at com.ibm.ws.webcontainer.srt.WebAppInvoker.handleInvocationHook(WebAppInvoker.java:214)
 at com.ibm.ws.webcontainer.cache.invocation.CachedInvocation.handleInvocation(CachedInvocation.java:71)
 at com.ibm.ws.webcontainer.srp.ServletRequestProcessor.dispatchByURI(ServletRequestProcessor.java:182)
 at com.ibm.ws.webcontainer.oselistener.OSEListenerDispatcher.service(OSEListener.java:334)
 at com.ibm.ws.webcontainer.http.HttpConnection.handleRequest(HttpConnection.java:56)
 at com.ibm.ws.http.HttpConnection.readAndHandleRequest(HttpConnection.java:615)
 at com.ibm.ws.http.HttpConnection.run(HttpConnection.java:439)
 at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:672)




Method B
wsadmin output sample information
(with application method leaking connections in bold)

PoolManager name:DefaultDatasource
PoolManager object:657570168
Total number of connections: 2 (max/min 30/1)
Pool Bucket configuration
 Shared Buckets: 200
 UnShared Buckets: 30
Shared Connection information
 (77) com.ibm.ws.LocalTransaction.LocalTranCoordImpl@6845b945  MCWrapper id e027979  Managed connection com.ibm.ws.rsadapter.spi.
WSRdbManagedConnectionImpl@1019f979  State:STATE_TRAN_WRAPPER_INUSE Thread Id: 67b03944 Thread Name: Servlet.Engine.Transports : 0
Start time inuse Wed Nov 03 11:31:26 CST 2004 Time inuse 21 (seconds)
 (77) com.ibm.ws.LocalTransaction.LocalTranCoordImpl@6845b945  MCWrapper id 5e31f97a  Managed connection com.ibm.ws.rsadapter.spi
.WSRdbManagedConnectionImpl@2b593979  State:STATE_TRAN_WRAPPER_INUSE Thread Id: 67b03944 Thread Name: Servlet.Engine.Transports :
0
Free Connection information

 No free connections

UnShared Connection information
 No unshared connections

Connection Leak Logic Information:
 MCWrapper id e027979  Managed connection com.ibm.ws.rsadapter.spi.WSRdbManagedConnectionImpl@1019f979  State:STATE_TRAN_WRAPPER_
INUSE Thread Id: 67b03944 Thread Name: Servlet.Engine.Transports : 0
    Start time inuse Wed Nov 03 11:31:26 CST 2004 Time inuse 21 (seconds)
    Last allocation time Wed Nov 03 11:31:26 CST 2004
      getConnection stack trace information:
         at com.ibm.ejs.j2c.poolmanager.PoolManager.reserve(PoolManager.java:1815)
       at com.ibm.ejs.j2c.ConnectionManager.allocateMCWrapper(ConnectionManager.java:689)
       at com.ibm.ejs.j2c.ConnectionManager.allocateConnection(ConnectionManager.java:456)
       at com.ibm.ws.rsadapter.jdbc.WSJdbcDataSource.getConnection(WSJdbcDataSource.java:215)
       at com.ibm.ws.rsadapter.jdbc.WSJdbcDataSource.getConnection(WSJdbcDataSource.java:306)
       at
SnoopServletTest.startTest1(SnoopServletTest.java:62)
       at SnoopServlet.doGet(SnoopServlet.java:103)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
       at com.ibm.ws.webcontainer.servlet.StrictServletInstance.doService(StrictServletInstance.java:110)
       at com.ibm.ws.webcontainer.servlet.StrictLifecycleServlet._service(StrictLifecycleServlet.java:174)
       at com.ibm.ws.webcontainer.servlet.IdleServletState.service(StrictLifecycleServlet.java:313)
       at com.ibm.ws.webcontainer.servlet.StrictLifecycleServlet.service(StrictLifecycleServlet.java:116)
       at com.ibm.ws.webcontainer.servlet.ServletInstance.service(ServletInstance.java:283)
       at com.ibm.ws.webcontainer.servlet.ValidServletReferenceState.dispatch(ValidServletReferenceState.java:42)
       at com.ibm.ws.webcontainer.servlet.ServletInstanceReference.dispatch(ServletInstanceReference.java:40)
       at com.ibm.ws.webcontainer.webapp.WebAppRequestDispatcher.handleWebAppDispatch(WebAppRequestDispatcher.java:1059)
       at com.ibm.ws.webcontainer.webapp.WebAppRequestDispatcher.dispatch(WebAppRequestDispatcher.java:588)
       at com.ibm.ws.webcontainer.webapp.WebAppRequestDispatcher.forward(WebAppRequestDispatcher.java:206)
       at com.ibm.ws.webcontainer.srt.WebAppInvoker.doForward(WebAppInvoker.java:80)
       at com.ibm.ws.webcontainer.srt.WebAppInvoker.handleInvocationHook(WebAppInvoker.java:214)
       at com.ibm.ws.webcontainer.cache.invocation.CachedInvocation.handleInvocation(CachedInvocation.java:71)
       at com.ibm.ws.webcontainer.srp.ServletRequestProcessor.dispatchByURI(ServletRequestProcessor.java:182)
       at com.ibm.ws.webcontainer.oselistener.OSEListenerDispatcher.service(OSEListener.java:334)
       at com.ibm.ws.webcontainer.http.HttpConnection.handleRequest(HttpConnection.java:56)
       at com.ibm.ws.http.HttpConnection.readAndHandleRequest(HttpConnection.java:615)
       at com.ibm.ws.http.HttpConnection.run(HttpConnection.java:439)
       at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:672)
 
j2c.propertiesconnectionLeakTraceLogic_51x.zipconnectionLeakTraceLogic_5.1.0.3 Instructions.html
 
Cross Reference information
Segment Product Component Platform Version Edition
Application Servers Runtimes for Java Technology Java SDK
 
 


Document Information


Product categories: Software > Application Servers > Distributed Application & Web Servers > WebSphere Application Server > DB Connections/Connection Pooling
Operating system(s): AIX
Software version: 5.1.1.3
Software edition:
Reference #: 1203225
IBM Group: Software Group
Modified date: Nov 30, 2006