X

Proactive insights, news and tips from Oracle WebLogic Server Support. Learn Oracle from Oracle.

  • November 4, 2015

Closed JDBC Object Profiling for WLS 12.2.1 Datasource

Stephen Felts
Manager

Accessing a closed JDBC object is a common application error
that can be difficult to debug. To help
diagnose such conditions there is a new profiling option to generate a
diagnostic log message when a JDBC object (Connection, Statement or ResultSet)
is accessed after the close() method has been invoked. The log message will include the stack trace
of the thread that invoked the close() method.

To enable closed JDBC object profiling, the datasource
ProfileType attribute bitmask must have the value 0x000400 set.

This is a WLST script to set the value.

# java weblogic.WLST prof.py

import sys, socket, os

hostname = socket.gethostname()

datasource='ds'

svr='myserver'

connect("weblogic","welcome1","t3://"+hostname+":7001")

# Edit the configuration to set the leak timeout

edit()

startEdit()

cd('/JDBCSystemResources/' + datasource + '/JDBCResource/' + datasource +
'/JDBCConnectionPoolParams/' +
datasource )

cmo.setProfileType(0x000400) # turn on profiling

save()

activate()

exit()

In the administrative console on the Diagnostics Tab, this may be enabled using the Profile Closed Usage checkbox. 

The closed usage log record contains two stack traces, one
of the thread that initially closed the object and another of the thread that
attempted to access the closed object. An example record is shown below.

####<mydatasource> <WEBLOGIC.JDBC.CLOSED_USAGE>
<Thu Apr 09 15:19:04 EDT 2015> <java.lang.Throwable: Thread[[ACTIVE]
ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)',5,Pooled
Threads]
at
weblogic.jdbc.common.internal.ProfileClosedUsage.saveWhereClosed(ProfileClosedUsage.java:31)
at
weblogic.jdbc.wrapper.PoolConnection.doClose(PoolConnection.java:242)
at
weblogic.jdbc.wrapper.PoolConnection.close(PoolConnection.java:157)
...

> <java.lang.Throwable: Thread[[ACTIVE] ExecuteThread: '2' for queue:
'weblogic.kernel.Default (self-tuning)',5,Pooled Threads]
at
weblogic.jdbc.common.internal.ProfileClosedUsage.addClosedUsageProfilingRecord(ProfileClosedUsage.java:38)
at weblogic.jdbc.wrapper.PoolConnection.checkConnection(PoolConnection.java:83)
at
weblogic.jdbc.wrapper.Connection.preInvocationHandler(Connection.java:106)
at
weblogic.jdbc.wrapper.Connection.createStatement(Connection.java:581)
...

> <[partition-id: 0] [partition-name: DOMAIN] >

When this profiling
option is enabled, exceptions indicating that an object is already closed will
also include a nested SQLException indicating where the close was done, as
shown in the example below.

java.sql.SQLException: Connection has already been closed.
at
weblogic.jdbc.wrapper.PoolConnection.checkConnection(PoolConnection.java:82)
at
weblogic.jdbc.wrapper.Connection.preInvocationHandler(Connection.java:107)
at weblogic.jdbc.wrapper.Connection.createStatement(Connection.java:582)

at
Application.doit(Application.java:156)
...

Caused by: java.sql.SQLException: Where closed: Thread[[ACTIVE] ExecuteThread:
...
at weblogic.jdbc.common.internal.ProfileClosedUsage.saveWhereClosed(ProfileClosedUsage.java:32)

at
weblogic.jdbc.wrapper.PoolConnection.doClose(PoolConnection.java:239)
at
weblogic.jdbc.wrapper.PoolConnection.close(PoolConnection.java:154)
at Application.doit(Application.java:154)

...

This is very helpful when you get an error indicating that a connection has already been closed and you can't figure out where it was done.  Note that there is overhead in getting the stack trace so you wouldn't normally run with this enabled all the time in production (and we don't default to it always being enabled), but it's worth the overhead when you need to resolve a problem.

Be the first to comment

Comments ( 0 )
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.Captcha
Oracle

Integrated Cloud Applications & Platform Services