Skip to main content
Skip table of contents

Viewing dump files for resource pools

You can view dump files that contain diagnostic information about the application's managed resource pool. You can use the files for troubleshooting purposes.
By default, dump files are automatically triggered when one of the following occurs:

  • Pool resources are exhausted
  • A potential leaked resource is detected
  • A previously potentially leaked resource is returned to the pool

Pooled resource diagnostics settings are configured in the environment file in NexJ Studio and are enabled by default. Changes to the settings require a redeploy of the application to take effect. For more information on configuring pooled resource diagnostics, see Configuring pooled resource diagnostics.

Pool resources are exhausted

The following example shows the contents of a dump file that was generated when pool resources were exhausted for a database connection.

CODE
2016-12-10 11:05:12,680 WARN  [nexj.diagnostic.core.rpc.pool.PoolManager] Automatic pool dump: 
   
   RelationalDatabaseConnectionPool@159749931(fragment=RelationalDatabaseFragment ObjectQueueDatabase.[default], busyTimeout=10000, idleTimeout=60000, maxSize=33, activeCount=3, idleCount=0)
      Active:
         SQLConnection@620363089(lastUse=10013ms, refCount=1, xaResource=SQLConnection$XAResourceWrapper@883133689(xaResource=JtdsXAResource@1568426606))
            DiagnosticTraceFactory$DiagnosticTraceHolder@184200117(threadName=NexJ Worker #2, transaction=GenericTransaction@2096453709(status="Active", id=Tx(0700000000000000C805BE154AFB35F5538D633BD1D81B4D)))
               scriptStack:
                  at Object.read(attributes,where,orderBy,count,offset,xlock)$beginTransactionIfXLock
(class:Object.read(attributes,where,orderBy,count,offset,xlock)
$beginTransactionIfXLock:6)
                  at server.read-instance(syslibrary:server:975)
                  at SysObjectQueueDispatcher.getDispatcher(locked)$main
(class:SysObjectQueueDispatcher.getDispatcher(locked)$main:5)
               systemStack:
                  at nexj.core.rpc.pool.DiagnosticTraceFactory.createTrace(DiagnosticTraceFactory.java:73)
                  at nexj.core.util.pool.resource.GenericResourcePool.get(GenericResourcePool.java:226)
                 at nexj.core.rpc.sql.RelationalDatabaseConnectionPool
.getConnection(RelationalDatabaseConnectionPool.java:160)
                  at nexj.core.persistence.sql.SQLAdapter.open(SQLAdapter.java:945)
                  at nexj.core.persistence.sql.SQLAdapter.getConnection(SQLAdapter.java:892)
                  at nexj.core.persistence.sql.SQLCursor.query(SQLCursor.java:158)
                  at nexj.core.persistence.GenericCursor.run(GenericCursor.java:484)
                  at nexj.core.persistence.GenericCursor.init(GenericCursor.java:274)
                  at nexj.core.persistence.GenericCursor.<init>(GenericCursor.java:189)
                  at nexj.core.persistence.sql.SQLCursor.<init>(SQLCursor.java:78)
                  at nexj.core.persistence.sql.SQLAdapter.openCursor(SQLAdapter.java:1218)
                  at nexj.core.persistence.GenericPersistenceAdapter.read
(GenericPersistenceAdapter.java:82)
                  at nexj.core.persistence.Query.read(Query.java:6000)
                  at nexj.core.runtime.sys.SysObject.read(SysObject.java:53)
                  at sun.reflect.GeneratedMethodAccessor38.invoke(Unknown Source)
                  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                  at java.lang.reflect.Method.invoke(Method.java:597)
                  at nexj.core.scripting.JavaAction.invoke(JavaAction.java:67)
                  at nexj.core.scripting.Machine.run(Machine.java:2121)
                  at nexj.core.scripting.Machine.invoke(Machine.java:639)
                  at nexj.core.meta.Event.invoke(Event.java:1617)
                  at nexj.core.meta.Metaclass.invoke(Metaclass.java:4110)
                  at nexj.core.rpc.queueing.ObjectQueueDispatcher$DispatchStrategy.run(ObjectQueueDispatcher.java:2634)
                  at nexj.core.integration.ContextReceiver$1.run(ContextReceiver.java:123)
                  at nexj.core.runtime.InvocationContext.run(InvocationContext.java:3016)
                  at nexj.core.integration.ContextReceiver.run(ContextReceiver.java:84)
                  at nexj.core.rpc.queueing.ObjectQueueDispatcher.dispatch(ObjectQueueDispatcher.java:1137)
                  at nexj.core.rpc.queueing.ObjectQueueDispatcher.onMessage(ObjectQueueDispatcher.java:635)
                  at nexj.core.rpc.queueing.ObjectQueueDispatcher.onMessage(ObjectQueueDispatcher.java:578)
                  at nexj.core.rpc.queueing.ObjectReceiver.onMessage(ObjectReceiver.java:108)
                  at nexj.core.rpc.queueing.ObjectQueueServerMDB.onMessage(ObjectQueueServerMDB.java:77)
                  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                  at java.lang.reflect.Method.invoke(Method.java:597)
                  at nexj.core.container.platform.teee.ejb.GenericMDBContainer.invoke
(GenericMDBContainer.java:112)
                  at nexj.core.container.platform.teee.ejb.MDBMessageEndpointFactory$ProxyHandler.invoke(MDBMessageEndpointFactory.java:286)
                  at com.sun.proxy.$Proxy5.onMessage(Unknown Source)
                  at nexj.core.rpc.queueing.ra.ObjectConsumerPool.invokeLocalDispatcher
(ObjectConsumerPool.java:454)
                  at nexj.core.rpc.queueing.ra.ObjectConsumerPool$DispatcherState.processMessages(ObjectConsumerPool.java:1211)
                  at nexj.core.rpc.queueing.ra.ObjectConsumerPool$DispatcherState.listen(ObjectConsumerPool.java:1680)
                  at nexj.core.rpc.queueing.ra.ObjectConsumerPool.listen(ObjectConsumerPool.java:191)
                  at nexj.core.rpc.ra.GenericConsumerPool.run(GenericConsumerPool.java:287)
                  at nexj.core.rpc.queueing.ra.ObjectConsumerPool.run(ObjectConsumerPool.java:421)
                  at nexj.core.container.platform.teee.ra.RAWorkManager$CheckedWork.run(RAWorkManager.java:154)
                  at nexj.core.container.platform.teee.work.GenericWorkerPool$Worker.run(GenericWorkerPool.java:326)

The following example shows the stacktrace that accompanies the pool dump file.

In the example, errors details are shown in the lines that contain the keywords (err.persistence.unavailable)and (err.pool.resource.busy).

CODE
2016-12-10 11:05:13,701 ERROR [nexj.core.rpc.cluster.ClusterManager] Error in heartbeat
nexj.core.persistence.AvailabilityException: Data source "DefaultRelationalDatabase" is temporarily unavailable. (err.persistence.unavailable)
                at nexj.core.persistence.sql.SQLAdapter.getConnection(SQLAdapter.java:896)
                at nexj.core.persistence.sql.SQLCursor.query(SQLCursor.java:158)
                at nexj.core.persistence.GenericCursor.run(GenericCursor.java:484)
                at nexj.core.persistence.GenericCursor.init(GenericCursor.java:274)
                at nexj.core.persistence.GenericCursor.<init>(GenericCursor.java:189)
                at nexj.core.persistence.sql.SQLCursor.<init>(SQLCursor.java:78)
                at nexj.core.persistence.sql.SQLAdapter.openCursor(SQLAdapter.java:1218)
                at nexj.core.persistence.GenericPersistenceAdapter.read
(GenericPersistenceAdapter.java:82)
                at nexj.core.persistence.Query.read(Query.java:6000)
                at nexj.core.rpc.cluster.ClusterManager.persist(ClusterManager.java:1277)
                at nexj.core.rpc.cluster.ClusterManager.heartbeat(ClusterManager.java:1391)
                at nexj.core.rpc.cluster.ClusterManager.timeout(ClusterManager.java:1456)
                at nexj.core.rpc.timer.PersistentTimer.process(PersistentTimer.java:479)
                at nexj.core.rpc.pool.GenericConsumerAdapter.process(GenericConsumerAdapter.java:157)
                at nexj.core.rpc.pool.DefaultConsumerAdapter.process(DefaultConsumerAdapter.java:22)
                at nexj.core.util.pool.consumer.GenericConsumer.process(GenericConsumer.java:303)
                at nexj.core.util.pool.consumer.GenericConsumer.consume(GenericConsumer.java:283)
                at nexj.core.rpc.timer.TimerConsumer.consume(TimerConsumer.java:66)
                at nexj.core.util.pool.consumer.GenericConsumer.run(GenericConsumer.java:200)
                at nexj.core.rpc.pool.ThreadPool$Worker$1$1.run(ThreadPool.java:244)
Caused by: nexj.core.util.pool.resource.PoolBusyException: Unable to allocate a resource in 10,000 ms due to reaching the maximum pool size of 33. (err.pool.resource.busy)
                at nexj.core.util.pool.resource.GenericResourcePool.get(GenericResourcePool.java:270)
                at nexj.core.rpc.sql.RelationalDatabaseConnectionPool.getConnection
(RelationalDatabaseConnectionPool.java:160)
                at nexj.core.persistence.sql.SQLAdapter.open(SQLAdapter.java:945)
                at nexj.core.persistence.sql.SQLAdapter.getConnection(SQLAdapter.java:892)
                ... 19 more

Potential leaked resource is detected

The following example shows the contents of a dump file that was generated when a potential leaked resource was detected for a database connection.

CODE
2016-12-10 11:20:29,625 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] Pool dump: The following resource(s) have been in use for more than 86400 s
   
   RelationalDatabaseConnectionPool@2112392140(fragment=RelationalDatabaseFragment DefaultRelationalDatabase.[default], busyTimeout=10000, idleTimeout=60000, maxSize=33, activeCount=1, idleCount=2)
      Active:
         SQLConnection@1250839995(lastUse=1000ms, refCount=1)
            DiagnosticTraceFactory$DiagnosticTraceHolder@256757984(threadName=NexJ TimerConsumer@1614732944(pool=TimerConsumerPool@210363069(config=Timer SystemTimer)) #342650404)
               systemStack:
                  at nexj.core.rpc.pool.DiagnosticTraceFactory.createTrace(DiagnosticTraceFactory.java:73)
                  at nexj.core.util.pool.resource.GenericResourcePool.get(GenericResourcePool.java:226)
                  at nexj.core.rpc.sql.RelationalDatabaseConnectionPool.getConnection
(RelationalDatabaseConnectionPool.java:160)
                  at nexj.core.persistence.sql.SQLAdapter.open(SQLAdapter.java:945)
                  at nexj.core.persistence.sql.SQLAdapter.getConnection(SQLAdapter.java:892)
                  at nexj.core.persistence.sql.SQLCursor.query(SQLCursor.java:158)
                  at nexj.core.persistence.GenericCursor.run(GenericCursor.java:484)
                  at nexj.core.persistence.GenericCursor.init(GenericCursor.java:274)
                  at nexj.core.persistence.GenericCursor.<init>(GenericCursor.java:189)
                  at nexj.core.persistence.sql.SQLCursor.<init>(SQLCursor.java:78)
                  at nexj.core.persistence.sql.SQLAdapter.openCursor(SQLAdapter.java:1218)
                  at nexj.core.persistence.GenericPersistenceAdapter.read
(GenericPersistenceAdapter.java:82)
                  at nexj.core.persistence.Query.read(Query.java:6000)
                  at nexj.core.rpc.cluster.ClusterManager.persist(ClusterManager.java:1277)
                  at nexj.core.rpc.cluster.ClusterManager.heartbeat(ClusterManager.java:1391)
                  at nexj.core.rpc.cluster.ClusterManager.timeout(ClusterManager.java:1456)
                  at nexj.core.rpc.timer.PersistentTimer.process(PersistentTimer.java:479)
                  at nexj.core.rpc.pool.GenericConsumerAdapter.process(GenericConsumerAdapter.java:157)
                  at nexj.core.rpc.pool.DefaultConsumerAdapter.process(DefaultConsumerAdapter.java:22)
                  at nexj.core.util.pool.consumer.GenericConsumer.process(GenericConsumer.java:303)
                  at nexj.core.util.pool.consumer.GenericConsumer.consume(GenericConsumer.java:283)
                  at nexj.core.rpc.timer.TimerConsumer.consume(TimerConsumer.java:66)
                  at nexj.core.util.pool.consumer.GenericConsumer.run(GenericConsumer.java:200)
                  at nexj.core.rpc.pool.ThreadPool$Worker$1$1.run(ThreadPool.java:244)

The following example shows the contents of a dump file that was generated when a potential leaked resource was detected for a timer.

CODE
2016-12-10 11:20:29,626 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] Pool dump: The following resource(s) have been in use for more than 86400 s
   
   TimerConsumerPool@210363069(config=Timer SystemTimer, idleTimeout=60000, maxSize=-1, activeCount=4, idleCount=4)
      Active:
         TimerConsumer@1689510533(lastUse=9905ms)
            DiagnosticTraceFactory$DiagnosticTraceHolder@982345134(threadName=NexJ TimerConsumerPool@210363069(config=Timer SystemTimer) #243642492)
               systemStack:
                  at nexj.core.rpc.pool.DiagnosticTraceFactory.createTrace(DiagnosticTraceFactory.java:73)
                  at nexj.core.util.pool.consumer.GenericConsumerPool.getConsumer
(GenericConsumerPool.java:612)
                  at nexj.core.rpc.timer.TimerConsumerPool.listen(TimerConsumerPool.java:213)
                  at nexj.core.util.pool.consumer.GenericConsumerPool.run(GenericConsumerPool.java:339)
                  at nexj.core.rpc.pool.ThreadPool$Worker$1$1.run(ThreadPool.java:244)
            
         TimerConsumer@1614732944(lastUse=1001ms)
            DiagnosticTraceFactory$DiagnosticTraceHolder@420389002(threadName=NexJ TimerConsumerPool@210363069(config=Timer SystemTimer) #243642492)
               systemStack:
                  at nexj.core.rpc.pool.DiagnosticTraceFactory.createTrace(DiagnosticTraceFactory.java:73)
                  at nexj.core.util.pool.consumer.GenericConsumerPool.getConsumer
(GenericConsumerPool.java:612)
                  at nexj.core.rpc.timer.TimerConsumerPool.listen(TimerConsumerPool.java:213)
                  at nexj.core.util.pool.consumer.GenericConsumerPool.run(GenericConsumerPool.java:339)
                  at nexj.core.rpc.pool.ThreadPool$Worker$1$1.run(ThreadPool.java:244)

The following example shows the contents of a dump file that was generated when a potential leaked resource was detected for a UDP connection.

CODE
2016-12-10 11:20:39,627 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] Pool dump: The following resource(s) have been in use for more than 86400 s
   
   UDPConsumerPool@1373030859(config=UDPChannel ClusterMulticastReceiver, idleTimeout=60000, maxSize=4, activeCount=1, idleCount=2)
      Active:
         UDPConsumer@795336456(lastUse=1753ms)
            DiagnosticTraceFactory$DiagnosticTraceHolder@94610066(threadName=NexJ UDPConsumerPool@1373030859(config=UDPChannel ClusterMulticastReceiver) #294728597)
               systemStack:
                  at nexj.core.rpc.pool.DiagnosticTraceFactory.createTrace(DiagnosticTraceFactory.java:73)
                  at nexj.core.util.pool.consumer.GenericConsumerPool.getConsumer
(GenericConsumerPool.java:612)
                  at nexj.core.rpc.udp.UDPConsumerPool.listen(UDPConsumerPool.java:153)
                  at nexj.core.util.pool.consumer.GenericConsumerPool.run(GenericConsumerPool.java:368)
                  at nexj.core.rpc.pool.ThreadPool$Worker$1$1.run(ThreadPool.java:244

Previously potentially leaked resource is returned to the pool

The following example shows the contents of a dump file that was generated when a previously potentially leaked resource for a database connection was returned to the pool.

CODE
2016-12-10 11:20:42,123 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] The following resource was previously reported as active but has been deactivated after 13 s:
   
   RelationalDatabaseConnectionPool@2112392140(fragment=RelationalDatabaseFragment DefaultRelationalDatabase.[default], busyTimeout=10000, idleTimeout=60000, maxSize=33, activeCount=2, idleCount=1)
      Idle:
         SQLConnection@1250839995(lastUse=13497ms, refCount=0)

The following example shows the contents of a dump file that was generated when a previously potentially leaked resource for a timer was returned to the pool.

CODE
2016-12-10 11:20:30,626 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] The following resource was previously reported as active but has been deactivated after 10 s:
   
   TimerConsumerPool@210363069(config=Timer SystemTimer, idleTimeout=60000, maxSize=-1, activeCount=3, idleCount=5)
      Idle:
         TimerConsumer@1689510533(lastUse=10906ms)

2016-12-10 11:20:42,149 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] The following resource was previously reported as active but has been deactivated after 13 s:
   
   TimerConsumerPool@210363069(config=Timer SystemTimer, idleTimeout=60000, maxSize=-1, activeCount=2, idleCount=6)
      Idle:
         TimerConsumer@1614732944(lastUse=13525ms)

The following example shows the contents of a dump file that was generated when a previously potentially leaked resource for a UDP connection was returned to the pool.

CODE
2016-12-10 11:20:40,863 INFO  [nexj.diagnostic.core.rpc.pool.PoolManager] The following resource was previously reported as active but has been deactivated after 0 s:
   
   UDPConsumerPool@1373030859(config=UDPChannel ClusterMulticastReceiver, idleTimeout=60000, maxSize=4, activeCount=2, idleCount=1)
      Idle:
         UDPConsumer@795336456(lastUse=7ms)

Interpreting resource pool diagnostic data
Collecting diagnostic data on dynamic resource pools

JavaScript errors detected

Please note, these errors can depend on your browser setup.

If this problem persists, please contact our support.