Hi,
We are experiencing a hung application once to twice a day in our production
environement. We run GlassFish 3.0.1 on Linux.
A thread dump from the hung application looks like this.
22 threads looks like this:
Thread Execution Information: -----------------------
Thread "http-thread-pool-8580-(190)" thread-id: 4,032 thread-state: BLOCKED
Waiting on lock: java.lang.Object_at_13c89d4
at:
com.sun.enterprise.resource.pool.ConnectionLeakDetector.startConnectionLeakTracing(ConnectionLeakDetector.java:109)
at:
com.sun.enterprise.resource.pool.ConnectionPool.setResourceStateToBusy(ConnectionPool.java:319)
at:
com.sun.enterprise.resource.pool.ConnectionPool.getMatchedResourceFromPool(ConnectionPool.java:752)
at:
com.sun.enterprise.resource.pool.ConnectionPool.resizePoolAndGetNewResource(ConnectionPool.java:729)
at:
com.sun.enterprise.resource.pool.ConnectionPool.getResourceFromPool(ConnectionPool.java:696)
at:
com.sun.enterprise.resource.pool.ConnectionPool.getUnenlistedResource(ConnectionPool.java:572)
at:
com.sun.enterprise.resource.pool.ConnectionPool.internalGetResource(ConnectionPool.java:467)
at:
com.sun.enterprise.resource.pool.ConnectionPool.getResource(ConnectionPool.java:369)
at:
com.sun.enterprise.resource.pool.PoolManagerImpl.getResourceFromPool(PoolManagerImpl.java:226)
at:
com.sun.enterprise.resource.pool.PoolManagerImpl.getResource(PoolManagerImpl.java:150)
...
at:
com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
at: java.lang.Thread.run(Thread.java:619)
Thread Synchronization Statistics:
-----------------------
This thread is blocked waiting on lock owned currently by thread named:
connector-timer-proxy, id: 206
Number of times this thread was blocked (to enter/reenter a Monitor): 1
Number of times this thread waited for a notification (i.e. it was in WAITING
or TIMED_WAITING state): 0
Total CPU time for this thread: 0 seconds 0 nanoseconds.
User-level CPU time for this thread: 0 seconds 0 nanoseconds.
Object Monitors currently held or requested by this thread: []
Ownable Synchronizers (e.g. ReentrantLock and ReentrantReadWriteLock) held by
this thread: []
The connector-timer-proxy thread they all are waiting for look like this:
Thread Execution Information: ----------------------- Thread
"connector-timer-proxy" thread-id: 206 thread-state: BLOCKED Waiting on lock:
com.ibm.db2.jcc.t4.c_at_a8376d at:
com.ibm.db2.jcc.am.lb.deregisterConnectionCallback(lb.java:7350) at:
com.ibm.db2.jcc.am.bf.a(bf.java:55) at:
com.ibm.db2.jcc.DB2PooledConnection.close(DB2PooledConnection.java:270) at:
com.ibm.db2.jcc.DB2XAConnection.close(DB2XAConnection.java:347) at:
com.sun.gjc.spi.ManagedConnection.destroy(ManagedConnection.java:343) at:
com.sun.enterprise.resource.allocator.ConnectorAllocator.destroyResource(ConnectorAllocator.java:188)
at:
com.sun.enterprise.resource.pool.ConnectionPool.deleteResource(ConnectionPool.java:884)
at:
com.sun.enterprise.resource.pool.datastructure.ListDataStructure.removeResource(ListDataStructure.java:174)
at:
com.sun.enterprise.resource.pool.ConnectionPool.reclaimConnection(ConnectionPool.java:1533)
at:
com.sun.enterprise.resource.pool.ConnectionLeakDetector.potentialConnectionLeakFound(ConnectionLeakDetector.java:156)
at:
com.sun.enterprise.resource.pool.ConnectionLeakDetector.access$000(ConnectionLeakDetector.java:55)
at:
com.sun.enterprise.resource.pool.ConnectionLeakDetector$ConnectionLeakTask.run(ConnectionLeakDetector.java:217)
at: java.util.TimerThread.mainLoop(Timer.java:512) at:
java.util.TimerThread.run(Timer.java:462) Thread Synchronization Statistics:
----------------------- This thread is blocked waiting on lock owned
currently by thread named: http-thread-pool-8580-(125), id: 3,630 Number of
times this thread was blocked (to enter/reenter a Monitor): 1 Number of times
this thread waited for a notification (i.e. it was in WAITING or
TIMED_WAITING state): 228 Total CPU time for this thread: 0 seconds
630,000,000 nanoseconds. User-level CPU time for this thread: 0 seconds
630,000,000 nanoseconds. Object Monitors currently held or requested by this
thread: [] Ownable Synchronizers (e.g. ReentrantLock and
ReentrantReadWriteLock) held by this thread: []
It is stated that it is waiting on a lock owned by thread
http-thread-pool-8580-(125). The information about this thread is as follows:
Thread Execution Information: ----------------------- Thread
"http-thread-pool-8580-(125)" thread-id: 3,630 thread-state: RUNNABLE Running
in native at: java.net.SocketInputStream.socketRead0(Native Method) at:
java.net.SocketInputStream.read(SocketInputStream.java:129) at:
com.ibm.db2.jcc.t4.z.b(z.java:200) at: com.ibm.db2.jcc.t4.z.c(z.java:260) at:
com.ibm.db2.jcc.t4.z.c(z.java:371) at: com.ibm.db2.jcc.t4.z.v(z.java:1146)
at: com.ibm.db2.jcc.t4.cb.d(cb.java:75) at: com.ibm.db2.jcc.t4.q.d(q.java:63)
at: com.ibm.db2.jcc.t4.rb.l(rb.java:170) at:
com.ibm.db2.jcc.am.en.jb(en.java:2012) at:
com.ibm.db2.jcc.am.fn.b(fn.java:3795) at:
com.ibm.db2.jcc.am.fn.ec(fn.java:738) at:
com.ibm.db2.jcc.am.fn.executeUpdate(fn.java:717) at:
com.ibm.db2.jcc.am.ef.executeUpdate(ef.java:78) at:
com.sun.gjc.spi.base.PreparedStatementWrapper.executeUpdate(PreparedStatementWrapper.java:108)
at: sun.reflect.GeneratedMethodAccessor106.invoke(Unknown Source) at:
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at: java.lang.reflect.Method.invoke(Method.java:597) at:
com.sun.gjc.spi.jdbc40.ProfiledConnectionWrapper40$1.invoke(ProfiledConnectionWrapper40.java:431)
at: $Proxy185.executeUpdate(Unknown Source) at:
com.sun.jdo.spi.persistence.support.sqlstore.sql.generator.DBStatement.executeUpdate(DBStatement.java:164)
at:
com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.executeUpdate(SQLStoreManager.java:207)
at:
com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.execute(SQLStoreManager.java:137)
at:
com.sun.jdo.spi.persistence.support.sqlstore.SQLStateManager.updatePersistent(SQLStateManager.java:924)
at:
com.sun.jdo.spi.persistence.support.sqlstore.impl.PersistenceManagerImpl.flushToDataStore(PersistenceManagerImpl.java:1499)
at:
com.sun.jdo.spi.persistence.support.sqlstore.impl.PersistenceManagerImpl.flushTxCache(PersistenceManagerImpl.java:1426)
at:
com.sun.jdo.spi.persistence.support.sqlstore.impl.PersistenceManagerImpl.beforeCompletion(PersistenceManagerImpl.java:1360)
at:
com.sun.jdo.spi.persistence.support.sqlstore.impl.TransactionImpl.notifyBeforeCompletion(TransactionImpl.java:1151)
at:
com.sun.jdo.spi.persistence.support.sqlstore.impl.TransactionImpl.commitBefore(TransactionImpl.java:790)
at:
com.sun.jdo.spi.persistence.support.sqlstore.impl.TransactionImpl.beforeCompletion(TransactionImpl.java:681)
at:
com.sun.ejb.containers.ContainerSynchronization.beforeCompletion(ContainerSynchronization.java:165)
at:
com.sun.jts.jta.SynchronizationImpl.before_completion(SynchronizationImpl.java:99)
at:
com.sun.jts.CosTransactions.RegisteredSyncs.distributeBefore(RegisteredSyncs.java:158)
at:
com.sun.jts.CosTransactions.TopCoordinator.beforeCompletion(TopCoordinator.java:2551)
at:
com.sun.jts.CosTransactions.CoordinatorTerm.commit(CoordinatorTerm.java:278)
at:
com.sun.jts.CosTransactions.TerminatorImpl.commit(TerminatorImpl.java:251)
at: com.sun.jts.CosTransactions.CurrentImpl.commit(CurrentImpl.java:623) at:
com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:318)
at:
com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:171)
at:
com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:843)
at:
com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5040)
at:
com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4805)
at: com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2004)
at: com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1955)
at:
com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:208)
at:
com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:118)
at: $Proxy164.commitCurrentJob(Unknown Source) at:
sun.reflect.GeneratedMethodAccessor843.invoke(Unknown Source) ... at:
com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791) at:
com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693) at:
com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954) at:
com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
at:
com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
at:
com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
at:
com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
at: com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
at:
com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
at:
com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
at: com.sun.grizzly.ContextTask.run(ContextTask.java:69) at:
com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
at:
com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
at: java.lang.Thread.run(Thread.java:619) Thread Synchronization Statistics:
----------------------- Number of times this thread was blocked (to
enter/reenter a Monitor): 102 Number of times this thread waited for a
notification (i.e. it was in WAITING or TIMED_WAITING state): 97 Total CPU
time for this thread: 1 seconds 850,000,000 nanoseconds. User-level CPU time
for this thread: 1 seconds 850,000,000 nanoseconds. Object Monitors currently
held or requested by this thread: [] Ownable Synchronizers (e.g.
ReentrantLock and ReentrantReadWriteLock) held by this thread: []
As you can see this thread is in RUNNABLE state and has only run for less
than 2 seconds. So why is connector-proxy-timer blocked?
It looks like my connection reclaim is not working as intended. Could this be
related to bug 3960 [1]?
Any input/help would be appreciated. Thanks.
[1]
http://java.net/jira/browse/GLASSFISH-3960
--
[Message sent by forum member 'mphaua']
View Post: http://forums.java.net/node/791264