[
https://issues.jboss.org/browse/JBJCA-1310?page=com.atlassian.jira.plugin...
]
Hugh Nguyen commented on JBJCA-1310:
------------------------------------
Hi Jesper,
I enabled the trace (however I still have to keep the statistics disabled, as I can't
bring the server down), and I got the following log.
The third line from the bottom, you can see that it reach line 436. If statistics is
enabled, then NPE would be thrown.
Thank you for your help.
{code}
2016-02-28 07:00:00,030 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager]
(DefaultQuartzScheduler_Worker-1) Subject: null
2016-02-28 07:00:00,030 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager]
(DefaultQuartzScheduler_Worker-1) getManagedConnection interleaving=false ,
tx=TransactionImple < ac, BasicAction: 0:ffffac10003c:13be63f2:56bd22e8:85c76 status:
ActionStatus.RUNNING >
2016-02-28 07:00:00,031 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) getConnection(null,
WrappedConnectionRequestInfo@4ac36f26[userName=db2admin])
Method: getConnection(null, WrappedConnectionRequestInfo@4ac36f26[userName=db2admin])
Subject: null
CRI: 4ac36f26
ManagedConnectionPool:
Class:
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool
Object: 10dbe79b
ManagedConnectionFactory:
Class:
org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$WildFlyXaMCF
Object: 28b22c2b
ConnectionManager:
Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
Object: 35431c37
Pool:
Name: ctrlDataSource
Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool
Object: 59164fb1
FIFO: false
PoolConfiguration:
MinSize: 5
InitialSize: 5
MaxSize: 100
BlockingTimeout: 30000
IdleTimeoutMinutes: 1
ValidateOnMatch: true
BackgroundValidation: false
BackgroundValidationMillis: 0
StrictMin: true
UseFastFail: false
Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer
Available (5):
7805dca2 (NORMAL) (Returned: 1456603200517) (Validated: 1456603200517) (Pool: 10799514)
192affde (NORMAL) (Returned: 1456603200554) (Validated: 1456603200544) (Pool: 10799477)
39236e5e (NORMAL) (Returned: 1456603200590) (Validated: 1456603200590) (Pool: 10799441)
63a41f42 (NORMAL) (Returned: 1456603200671) (Validated: 1456603200671) (Pool: 10799360)
19e47679 (NORMAL) (Returned: 1456610400386) (Validated: 1456603200715) (Pool: 3599645)
InUse (0):
Statistics:
ActiveCount: 0
AvailableCount: 0
AverageBlockingTime: 0
AverageCreationTime: 0
AverageGetTime: 0
AveragePoolTime: 0
AverageUsageTime: 0
BlockingFailureCount: 0
CreatedCount: 0
DestroyedCount: 0
IdleCount: 0
InUseCount: 0
MaxCreationTime: 0
MaxGetTime: 0
MaxPoolTime: 0
MaxUsageTime: 0
MaxUsedCount: 0
MaxWaitTime: 0
TimedOut: 0
TotalBlockingTime: 0
TotalCreationTime: 0
TotalGetTime: 0
TotalPoolTime: 0
TotalUsageTime: 0
WaitCount: 0
XAResource:
CommitCount: 0
CommitTotalTime: 0
CommitAverageTime: 0
CommitMaxTime: 0
EndCount: 0
EndTotalTime: 0
EndAverageTime: 0
EndMaxTime: 0
ForgetCount: 0
ForgetTotalTime: 0
ForgetAverageTime: 0
ForgetMaxTime: 0
PrepareCount: 0
PrepareTotalTime: 0
PrepareAverageTime: 0
PrepareMaxTime: 0
RecoverCount: 0
RecoverTotalTime: 0
RecoverAverageTime: 0
RecoverMaxTime: 0
RollbackCount: 0
RollbackTotalTime: 0
RollbackAverageTime: 0
RollbackMaxTime: 0
StartCount: 0
StartTotalTime: 0
StartAverageTime: 0
StartMaxTime: 0
2016-02-28 07:00:00,039 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) supplying ManagedConnection from pool:
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456610400382 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null]
2016-02-28 07:00:00,040 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) Got connection from pool tracked by
transaction=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null] tx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING >
2016-02-28 07:00:00,040 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) Using connection from pool tracked by
transaction=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null] tx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING >
2016-02-28 07:00:00,040 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) Pre-enlist:
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null] threadTx=TransactionImple < ac,
BasicAction: 0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING >
2016-02-28 07:00:00,040 TRACE
[org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer]
(DefaultQuartzScheduler_Worker-1) Adding: 520529016 [TransactionImple < ac,
BasicAction: 0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING >]
2016-02-28 07:00:00,040 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) Get synchronizer
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null] threadTx=TransactionImple < ac,
BasicAction: 0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING >
2016-02-28 07:00:00,040 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1)
TransactionSynchronization@1580160865{tx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING > wasTrackByTx=true
enlisted=false cancel=false}: Constructor
2016-02-28 07:00:00,040 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) Enlisting resource
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource]
txSync=TransactionSynchronization@1580160865{tx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING > wasTrackByTx=true
enlisted=false cancel=false}]
2016-02-28 07:00:00,041 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) Enlisted resource
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource]
txSync=TransactionSynchronization@1580160865{tx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING > wasTrackByTx=true
enlisted=true cancel=false}]
2016-02-28 07:00:00,041 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) Check enlisted
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource]
txSync=TransactionSynchronization@1580160865{tx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING > wasTrackByTx=true
enlisted=true cancel=false}] threadTx=TransactionImple < ac, BasicAction:
0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.RUNNING >
2016-02-28 07:00:00,041 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) [TxConnectionListener@19e47679] registerConnection:
org.jboss.jca.adapters.jdbc.jdk7.WrappedConnectionJDK7@3dce223a [size=1]
([org.jboss.jca.adapters.jdbc.jdk7.WrappedConnectionJDK7@3dce223a])
2016-02-28 07:00:00,041 TRACE
[org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager]
(DefaultQuartzScheduler_Worker-1) registering connection from connection manager:
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@35431c37, connection :
org.jboss.jca.adapters.jdbc.jdk7.WrappedConnectionJDK7@3dce223a, key: null
2016-02-28 07:00:00,099 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper]
(DefaultQuartzScheduler_Worker-1) SQL Warning Code: 4223, SQLState: null
2016-02-28 07:00:00,099 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper]
(DefaultQuartzScheduler_Worker-1) Origination unknown: [10228][11541][4.14.122] Security
exceptions occurred while loading driver. ERRORCODE=4223, SQLSTATE=null
2016-02-28 07:00:00,099 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) connectionClosed called
mc=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408
2016-02-28 07:00:00,099 TRACE
[org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager]
(DefaultQuartzScheduler_Worker-1) unregistering connection from connection manager:
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@35431c37, connection:
org.jboss.jca.adapters.jdbc.jdk7.WrappedConnectionJDK7@3dce223a, key: null
2016-02-28 07:00:00,099 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) [TxConnectionListener@19e47679] unregisterConnection: 0
handles left ([])
2016-02-28 07:00:00,099 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) isManagedConnectionFree=false
mc=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408
2016-02-28 07:00:00,099 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1)
delistResource(XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource], TMSUCCESS)
2016-02-28 07:00:00,100 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) afterCompletion(3) isTrackByTx=true for
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456610400386 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=true
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null]
2016-02-28 07:00:00,100 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) [TxConnectionListener@19e47679] isManagedConnectionFree:
true
2016-02-28 07:00:00,100 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) returnConnection(19e47679, false)
Method: returnConnection(19e47679, false)
Subject: null
CRI: null
ManagedConnectionPool:
Class:
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool
Object: 10dbe79b
ManagedConnectionFactory:
Class:
org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$WildFlyXaMCF
Object: 28b22c2b
ConnectionManager:
Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
Object: 35431c37
Pool:
Name: ctrlDataSource
Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool
Object: 59164fb1
FIFO: false
PoolConfiguration:
MinSize: 5
InitialSize: 5
MaxSize: 100
BlockingTimeout: 30000
IdleTimeoutMinutes: 1
ValidateOnMatch: true
BackgroundValidation: false
BackgroundValidationMillis: 0
StrictMin: true
UseFastFail: false
Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer
Available (4):
7805dca2 (NORMAL) (Returned: 1456603200517) (Validated: 1456603200517) (Pool: 10799583)
192affde (NORMAL) (Returned: 1456603200554) (Validated: 1456603200544) (Pool: 10799546)
39236e5e (NORMAL) (Returned: 1456603200590) (Validated: 1456603200590) (Pool: 10799510)
63a41f42 (NORMAL) (Returned: 1456603200671) (Validated: 1456603200671) (Pool: 10799429)
InUse (1):
19e47679 (NORMAL) (CheckedOut: 1456614000040) (Validated: 1456603200715) (Usage: 60)
Statistics:
ActiveCount: 0
AvailableCount: 0
AverageBlockingTime: 0
AverageCreationTime: 0
AverageGetTime: 0
AveragePoolTime: 0
AverageUsageTime: 0
BlockingFailureCount: 0
CreatedCount: 0
DestroyedCount: 0
IdleCount: 0
InUseCount: 0
MaxCreationTime: 0
MaxGetTime: 0
MaxPoolTime: 0
MaxUsageTime: 0
MaxUsedCount: 0
MaxWaitTime: 0
TimedOut: 0
TotalBlockingTime: 0
TotalCreationTime: 0
TotalGetTime: 0
TotalPoolTime: 0
TotalUsageTime: 0
WaitCount: 0
XAResource:
CommitCount: 0
CommitTotalTime: 0
CommitAverageTime: 0
CommitMaxTime: 0
EndCount: 0
EndTotalTime: 0
EndAverageTime: 0
EndMaxTime: 0
ForgetCount: 0
ForgetTotalTime: 0
ForgetAverageTime: 0
ForgetMaxTime: 0
PrepareCount: 0
PrepareTotalTime: 0
PrepareAverageTime: 0
PrepareMaxTime: 0
RecoverCount: 0
RecoverTotalTime: 0
RecoverAverageTime: 0
RecoverMaxTime: 0
RollbackCount: 0
RollbackTotalTime: 0
RollbackAverageTime: 0
RollbackMaxTime: 0
StartCount: 0
StartTotalTime: 0
StartAverageTime: 0
StartMaxTime: 0
2016-02-28 07:00:00,100 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) Returning connection to pool
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@19e47679[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@5af92408 connection
handles=0 lastReturned=1456614000100 lastValidated=1456603200715
lastCheckedOut=1456614000040 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@59164fb1
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@10dbe79b[pool=ctrlDataSource]
xaResource=XAResourceWrapperImpl@253673cd[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)5af92408
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/ctrlDataSource] txSync=null]
2016-02-28 07:00:00,100 TRACE
[org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer]
(DefaultQuartzScheduler_Worker-1) Removed: 520529016 [TransactionImple < ac,
BasicAction: 0:ffffac10003c:13be63f2:56bd22e8:85c76 status: ActionStatus.COMMITTED >]
2016-02-28 07:00:00,101 DEBUG [synergix.th6.framework.persistence.SynEntityManagerImpl]
(DefaultQuartzScheduler_Worker-1) SynEntityManager CLOSED: SynEntityManagerImpl@3def80f1 -
{companyCode=CTRL,
entityManagerRegistry=TransactionScopedEntityManagerRegistryImpl@48656ce2}
2016-02-28 07:00:00,101 DEBUG [synergix.th6.framework.persistence.SynEntityManagerFactory]
(DefaultQuartzScheduler_Worker-1)
SynEntityManagerFactory.disposeSynEntityManager(SynEntityManagerImpl@3def80f1 -
{companyCode=CTRL,
entityManagerRegistry=TransactionScopedEntityManagerRegistryImpl@48656ce2})
2016-02-28 07:00:00,102 DEBUG [synergix.th6.business.util.persistence.EmLocator]
(DefaultQuartzScheduler_Worker-1) Current Company Code not available in User Session.
Retrieved from ThreadLocal: LS1INT
2016-02-28 07:00:00,103 DEBUG [synergix.th6.framework.persistence.SynEntityManagerFactory]
(DefaultQuartzScheduler_Worker-1) SynEntityManager CREATED: SynEntityManagerImpl@5f0258a5
- {companyCode=LS1INT,
entityManagerRegistry=TransactionScopedEntityManagerRegistryImpl@40137234}
2016-02-28 07:00:00,103 DEBUG [org.hibernate.SQL] (DefaultQuartzScheduler_Worker-1) select
mt_sys_rev0_.employment_type_code as employme1_1706_0_, mt_sys_rev0_.review_type_code as
review_t2_1706_0_, mt_sys_rev0_.created_by as created_3_1706_0_,
mt_sys_rev0_.created_datetime as created_4_1706_0_, mt_sys_rev0_.last_updated_by as
last_upd5_1706_0_, mt_sys_rev0_.last_updated_datetime as last_upd6_1706_0_,
mt_sys_rev0_.object_version as object_v7_1706_0_, mt_sys_rev0_.check_mt_employee_exclusion
as check_mt8_1706_0_, mt_sys_rev0_.reminder_frequency as reminder9_1706_0_,
mt_sys_rev0_.reminder_to_flow_seq as reminde10_1706_0_, mt_sys_rev0_.EMPLOYMENT_TYPE_CODE
as EMPLOYME1_1706_0_, mt_sys_rev0_.REVIEW_TYPE_CODE as REVIEW_T2_1706_0_,
mt_sys_rev0_.trigger_code as trigger11_1706_0_, mt_sys_rev0_.trigger_param_1 as
trigger12_1706_0_, mt_sys_rev0_.trigger_param_2 as trigger13_1706_0_,
mt_sys_rev0_.week_day_to_remind_reviewer as week_da14_1706_0_ from
Mt_sys_review_trigger_and_reminder mt_sys_rev0_ where mt_sys_rev0_.employment_type_code=?
and mt_sys_rev0_.review_type_code=?
2016-02-28 07:00:00,103 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager]
(DefaultQuartzScheduler_Worker-1) Subject: null
2016-02-28 07:00:00,103 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager]
(DefaultQuartzScheduler_Worker-1) getManagedConnection interleaving=false ,
tx=TransactionImple < ac, BasicAction: 0:ffffac10003c:13be63f2:56bd22e8:85c7d status:
ActionStatus.RUNNING >
2016-02-28 07:00:00,103 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) getConnection(null,
WrappedConnectionRequestInfo@5e6abda5[userName=db2admin])
Method: getConnection(null, WrappedConnectionRequestInfo@5e6abda5[userName=db2admin])
Subject: null
CRI: 5e6abda5
ManagedConnectionPool:
Class:
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool
Object: 2665f4d6
ManagedConnectionFactory:
Class:
org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$WildFlyXaMCF
Object: 50907673
ConnectionManager:
Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
Object: 1075eec3
Pool:
Name: pemain1
Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool
Object: 55209893
FIFO: false
PoolConfiguration:
MinSize: 5
InitialSize: 5
MaxSize: 100
BlockingTimeout: 30000
IdleTimeoutMinutes: 1
ValidateOnMatch: true
BackgroundValidation: false
BackgroundValidationMillis: 0
StrictMin: true
UseFastFail: false
Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer
Available (5):
322500c (NORMAL) (Returned: 1456527600419) (Validated: 1456527600419) (Pool: 86399684)
35bd4931 (NORMAL) (Returned: 1456527600471) (Validated: 1456527600455) (Pool: 86399632)
8d8ede3 (NORMAL) (Returned: 1456527600502) (Validated: 1456527600502) (Pool: 86399601)
6fd4da32 (NORMAL) (Returned: 1456527600550) (Validated: 1456527600550) (Pool: 86399553)
4aad6c0 (NORMAL) (Returned: 1456554069609) (Validated: 1456527600612) (Pool: 59930494)
InUse (0):
Statistics:
ActiveCount: 0
AvailableCount: 0
AverageBlockingTime: 0
AverageCreationTime: 0
AverageGetTime: 0
AveragePoolTime: 0
AverageUsageTime: 0
BlockingFailureCount: 0
CreatedCount: 0
DestroyedCount: 0
IdleCount: 0
InUseCount: 0
MaxCreationTime: 0
MaxGetTime: 0
MaxPoolTime: 0
MaxUsageTime: 0
MaxUsedCount: 0
MaxWaitTime: 0
TimedOut: 0
TotalBlockingTime: 0
TotalCreationTime: 0
TotalGetTime: 0
TotalPoolTime: 0
TotalUsageTime: 0
WaitCount: 0
XAResource:
CommitCount: 0
CommitTotalTime: 0
CommitAverageTime: 0
CommitMaxTime: 0
EndCount: 0
EndTotalTime: 0
EndAverageTime: 0
EndMaxTime: 0
ForgetCount: 0
ForgetTotalTime: 0
ForgetAverageTime: 0
ForgetMaxTime: 0
PrepareCount: 0
PrepareTotalTime: 0
PrepareAverageTime: 0
PrepareMaxTime: 0
RecoverCount: 0
RecoverTotalTime: 0
RecoverAverageTime: 0
RecoverMaxTime: 0
RollbackCount: 0
RollbackTotalTime: 0
RollbackAverageTime: 0
RollbackMaxTime: 0
StartCount: 0
StartTotalTime: 0
StartAverageTime: 0
StartMaxTime: 0
2016-02-28 07:00:00,106 WARN
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) IJ000305: Connection error occured:
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@4aad6c0[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@4d66892d connection
handles=0 lastReturned=1456554069609 lastValidated=1456527600612
lastCheckedOut=1456554069554 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@55209893
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@2665f4d6[pool=pemain1]
xaResource=XAResourceWrapperImpl@9a0673a[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)4d66892d
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/PEMAIN1] txSync=null]:
com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException:
[jcc][t4][2030][11211][4.14.122] A communication error occurred during operations on the
connection's underlying socket, socket input stream,
or socket output stream. Error location: T4Agent.sendRequest() - flush (-1). Message:
Software caused connection abort: socket write error. ERRORCODE=-4499, SQLSTATE=08001
at com.ibm.db2.jcc.am.ed.a(ed.java:320)
at com.ibm.db2.jcc.t4.a.a(a.java:546)
at com.ibm.db2.jcc.t4.a.a(a.java:541)
at com.ibm.db2.jcc.t4.a.f(a.java:482)
at com.ibm.db2.jcc.t4.a.flush_(a.java:388)
at com.ibm.db2.jcc.am.Agent.flow(Agent.java:231)
at com.ibm.db2.jcc.am.oo.a(oo.java:3178)
at com.ibm.db2.jcc.am.oo.e(oo.java:1073)
at com.ibm.db2.jcc.am.oo.execute(oo.java:1056)
at
org.jboss.jca.adapters.jdbc.extensions.db2.DB2ValidConnectionChecker.isValidConnection(DB2ValidConnectionChecker.java:65)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1261)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.checkValid(BaseWrapperManagedConnection.java:508)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.getInvalidConnections(BaseWrapperManagedConnectionFactory.java:1082)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:378)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:708)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:607)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:590)
at
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:429)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:747)
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)
at
org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:66)
at
org.hibernate.engine.jdbc.connections.spi.AbstractDataSourceBasedMultiTenantConnectionProviderImpl.getConnection(AbstractDataSourceBasedMultiTenantConnectionProviderImpl.java:35)
at
org.hibernate.internal.AbstractSessionImpl$ContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:429)
at
org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:87)
at
org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:112)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.prepareQueryStatement(AbstractLoadPlanBasedLoader.java:241)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:185)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:121)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
at
org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:167)
at
org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3956)
at
org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:508)
at
org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:478)
at
org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:219)
at
org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:278)
at
org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:121)
at
org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:89)
at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1129)
at org.hibernate.internal.SessionImpl.access$2600(SessionImpl.java:164)
at
org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2696)
at org.hibernate.internal.SessionImpl.get(SessionImpl.java:975)
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:1075)
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:1033)
at
synergix.th6.framework.persistence.EntityManagerAbstractWrapper.find(EntityManagerAbstractWrapper.java:50)
at
synergix.th6.business.entity.mtsys.Mt_sys_review_trigger_and_reminder.find(Mt_sys_review_trigger_and_reminder.java:37)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.triggerYearEnd(InitiateReviewsJob.java:74)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.access$0(InitiateReviewsJob.java:73)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob$2.call(InitiateReviewsJob.java:56)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob$2.call(InitiateReviewsJob.java:1)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor.__do_not_call_directly_executeWithIsolatedTransaction(IsolatedTransactionExecutor.java:27)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor$Proxy$_$$_WeldSubclass.__do_not_call_directly_executeWithIsolatedTransaction$$super(Unknown
Source)
at sun.reflect.GeneratedMethodAccessor2385.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49)
at
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:117)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:60)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:76)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:47)
at sun.reflect.GeneratedMethodAccessor2384.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor$Proxy$_$$_WeldSubclass.__do_not_call_directly_executeWithIsolatedTransaction(Unknown
Source)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor$Proxy$_$$_WeldClientProxy.__do_not_call_directly_executeWithIsolatedTransaction(Unknown
Source)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor.executeWithIsolatedTransaction(IsolatedTransactionExecutor.java:14)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.triggerReviews(InitiateReviewsJob.java:49)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.execute(InitiateReviewsJob.java:34)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: java.net.SocketException: Software caused connection abort: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
at com.ibm.db2.jcc.t4.db.b(db.java:1685)
at com.ibm.db2.jcc.t4.db.a(db.java:1633)
at com.ibm.db2.jcc.t4.a.f(a.java:449)
... 76 more
2016-02-28 07:00:00,110 TRACE
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) [TxConnectionListener@4aad6c0] unregisterConnections
2016-02-28 07:00:00,110 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) returnConnection(4aad6c0, true)
Method: returnConnection(4aad6c0, true)
Subject: null
CRI: null
ManagedConnectionPool:
Class:
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool
Object: 2665f4d6
ManagedConnectionFactory:
Class:
org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$WildFlyXaMCF
Object: 50907673
ConnectionManager:
Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
Object: 1075eec3
Pool:
Name: pemain1
Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool
Object: 55209893
FIFO: false
PoolConfiguration:
MinSize: 5
InitialSize: 5
MaxSize: 100
BlockingTimeout: 30000
IdleTimeoutMinutes: 1
ValidateOnMatch: true
BackgroundValidation: false
BackgroundValidationMillis: 0
StrictMin: true
UseFastFail: false
Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer
Available (4):
322500c (NORMAL) (Returned: 1456527600419) (Validated: 1456527600419) (Pool: 86399691)
35bd4931 (NORMAL) (Returned: 1456527600471) (Validated: 1456527600455) (Pool: 86399639)
8d8ede3 (NORMAL) (Returned: 1456527600502) (Validated: 1456527600502) (Pool: 86399608)
6fd4da32 (NORMAL) (Returned: 1456527600550) (Validated: 1456527600550) (Pool: 86399560)
InUse (1):
4aad6c0 (NORMAL) (CheckedOut: 1456554069554) (Validated: 1456527600612) (Usage:
59930556)
Statistics:
ActiveCount: 0
AvailableCount: 0
AverageBlockingTime: 0
AverageCreationTime: 0
AverageGetTime: 0
AveragePoolTime: 0
AverageUsageTime: 0
BlockingFailureCount: 0
CreatedCount: 0
DestroyedCount: 0
IdleCount: 0
InUseCount: 0
MaxCreationTime: 0
MaxGetTime: 0
MaxPoolTime: 0
MaxUsageTime: 0
MaxUsedCount: 0
MaxWaitTime: 0
TimedOut: 0
TotalBlockingTime: 0
TotalCreationTime: 0
TotalGetTime: 0
TotalPoolTime: 0
TotalUsageTime: 0
WaitCount: 0
XAResource:
CommitCount: 0
CommitTotalTime: 0
CommitAverageTime: 0
CommitMaxTime: 0
EndCount: 0
EndTotalTime: 0
EndAverageTime: 0
EndMaxTime: 0
ForgetCount: 0
ForgetTotalTime: 0
ForgetAverageTime: 0
ForgetMaxTime: 0
PrepareCount: 0
PrepareTotalTime: 0
PrepareAverageTime: 0
PrepareMaxTime: 0
RecoverCount: 0
RecoverTotalTime: 0
RecoverAverageTime: 0
RecoverMaxTime: 0
RollbackCount: 0
RollbackTotalTime: 0
RollbackAverageTime: 0
RollbackMaxTime: 0
StartCount: 0
StartTotalTime: 0
StartAverageTime: 0
StartMaxTime: 0
2016-02-28 07:00:00,111 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) Destroying returned connection
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@4aad6c0[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@4d66892d connection
handles=0 lastReturned=1456554069609 lastValidated=1456527600612
lastCheckedOut=1456554069554 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@55209893
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@2665f4d6[pool=pemain1]
xaResource=XAResourceWrapperImpl@9a0673a[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)4d66892d
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/PEMAIN1] txSync=null]
2016-02-28 07:00:00,111 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) Returning connection to pool
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@4aad6c0[state=DESTROYED
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@4d66892d connection
handles=0 lastReturned=1456554069609 lastValidated=1456527600612
lastCheckedOut=1456554069554 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@55209893
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@2665f4d6[pool=pemain1]
xaResource=XAResourceWrapperImpl@9a0673a[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)4d66892d
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/PEMAIN1] txSync=null]
2016-02-28 07:00:00,112 WARN
[org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$WildFlyXaMCF]
(DefaultQuartzScheduler_Worker-1) IJ030027: Destroying connection that is not valid, due
to the following exception: com.ibm.db2.jcc.am.ef@12be0aa4:
com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException:
[jcc][t4][2030][11211][4.14.122] A communication error occurred during operations on the
connection's underlying socket, socket input stream,
or socket output stream. Error location: T4Agent.sendRequest() - flush (-1). Message:
Software caused connection abort: socket write error. ERRORCODE=-4499, SQLSTATE=08001
at com.ibm.db2.jcc.am.ed.a(ed.java:320)
at com.ibm.db2.jcc.t4.a.a(a.java:546)
at com.ibm.db2.jcc.t4.a.a(a.java:541)
at com.ibm.db2.jcc.t4.a.f(a.java:482)
at com.ibm.db2.jcc.t4.a.flush_(a.java:388)
at com.ibm.db2.jcc.am.Agent.flow(Agent.java:231)
at com.ibm.db2.jcc.am.oo.a(oo.java:3178)
at com.ibm.db2.jcc.am.oo.e(oo.java:1073)
at com.ibm.db2.jcc.am.oo.execute(oo.java:1056)
at
org.jboss.jca.adapters.jdbc.extensions.db2.DB2ValidConnectionChecker.isValidConnection(DB2ValidConnectionChecker.java:65)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1261)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.checkValid(BaseWrapperManagedConnection.java:508)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.getInvalidConnections(BaseWrapperManagedConnectionFactory.java:1082)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:378)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:708)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:607)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:590)
at
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:429)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:747)
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)
at
org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:66)
at
org.hibernate.engine.jdbc.connections.spi.AbstractDataSourceBasedMultiTenantConnectionProviderImpl.getConnection(AbstractDataSourceBasedMultiTenantConnectionProviderImpl.java:35)
at
org.hibernate.internal.AbstractSessionImpl$ContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:429)
at
org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:87)
at
org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:112)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172)
at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.prepareQueryStatement(AbstractLoadPlanBasedLoader.java:241)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:185)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:121)
at
org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
at
org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:167)
at
org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3956)
at
org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:508)
at
org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:478)
at
org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:219)
at
org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:278)
at
org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:121)
at
org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:89)
at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1129)
at org.hibernate.internal.SessionImpl.access$2600(SessionImpl.java:164)
at
org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2696)
at org.hibernate.internal.SessionImpl.get(SessionImpl.java:975)
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:1075)
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:1033)
at
synergix.th6.framework.persistence.EntityManagerAbstractWrapper.find(EntityManagerAbstractWrapper.java:50)
at
synergix.th6.business.entity.mtsys.Mt_sys_review_trigger_and_reminder.find(Mt_sys_review_trigger_and_reminder.java:37)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.triggerYearEnd(InitiateReviewsJob.java:74)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.access$0(InitiateReviewsJob.java:73)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob$2.call(InitiateReviewsJob.java:56)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob$2.call(InitiateReviewsJob.java:1)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor.__do_not_call_directly_executeWithIsolatedTransaction(IsolatedTransactionExecutor.java:27)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor$Proxy$_$$_WeldSubclass.__do_not_call_directly_executeWithIsolatedTransaction$$super(Unknown
Source)
at sun.reflect.GeneratedMethodAccessor2385.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49)
at
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:117)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:60)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:76)
at
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:47)
at sun.reflect.GeneratedMethodAccessor2384.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor$Proxy$_$$_WeldSubclass.__do_not_call_directly_executeWithIsolatedTransaction(Unknown
Source)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor$Proxy$_$$_WeldClientProxy.__do_not_call_directly_executeWithIsolatedTransaction(Unknown
Source)
at
synergix.th6.framework.persistence.transaction.IsolatedTransactionExecutor.executeWithIsolatedTransaction(IsolatedTransactionExecutor.java:14)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.triggerReviews(InitiateReviewsJob.java:49)
at
synergix.th6.business.action.scheduledjob.hr.InitiateReviewsJob.execute(InitiateReviewsJob.java:34)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: java.net.SocketException: Software caused connection abort: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
at com.ibm.db2.jcc.t4.db.b(db.java:1685)
at com.ibm.db2.jcc.t4.db.a(db.java:1633)
at com.ibm.db2.jcc.t4.a.f(a.java:449)
... 76 more
2016-02-28 07:00:00,112 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(JCA PoolFiller) fillTo(5)
Method: fillTo(5)
Subject: null
CRI: null
ManagedConnectionPool:
Class:
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool
Object: 2665f4d6
ManagedConnectionFactory:
Class:
org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$WildFlyXaMCF
Object: 50907673
ConnectionManager:
Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
Object: 1075eec3
Pool:
Name: pemain1
Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool
Object: 55209893
FIFO: false
PoolConfiguration:
MinSize: 5
InitialSize: 5
MaxSize: 100
BlockingTimeout: 30000
IdleTimeoutMinutes: 1
ValidateOnMatch: true
BackgroundValidation: false
BackgroundValidationMillis: 0
StrictMin: true
UseFastFail: false
Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer
Available (4):
322500c (NORMAL) (Returned: 1456527600419) (Validated: 1456527600419) (Pool: 86399693)
35bd4931 (NORMAL) (Returned: 1456527600471) (Validated: 1456527600455) (Pool: 86399641)
8d8ede3 (NORMAL) (Returned: 1456527600502) (Validated: 1456527600502) (Pool: 86399610)
6fd4da32 (NORMAL) (Returned: 1456527600550) (Validated: 1456527600550) (Pool: 86399562)
InUse (0):
Statistics:
ActiveCount: 0
AvailableCount: 0
AverageBlockingTime: 0
AverageCreationTime: 0
AverageGetTime: 0
AveragePoolTime: 0
AverageUsageTime: 0
BlockingFailureCount: 0
CreatedCount: 0
DestroyedCount: 0
IdleCount: 0
InUseCount: 0
MaxCreationTime: 0
MaxGetTime: 0
MaxPoolTime: 0
MaxUsageTime: 0
MaxUsedCount: 0
MaxWaitTime: 0
TimedOut: 0
TotalBlockingTime: 0
TotalCreationTime: 0
TotalGetTime: 0
TotalPoolTime: 0
TotalUsageTime: 0
WaitCount: 0
XAResource:
CommitCount: 0
CommitTotalTime: 0
CommitAverageTime: 0
CommitMaxTime: 0
EndCount: 0
EndTotalTime: 0
EndAverageTime: 0
EndMaxTime: 0
ForgetCount: 0
ForgetTotalTime: 0
ForgetAverageTime: 0
ForgetMaxTime: 0
PrepareCount: 0
PrepareTotalTime: 0
PrepareAverageTime: 0
PrepareMaxTime: 0
RecoverCount: 0
RecoverTotalTime: 0
RecoverAverageTime: 0
RecoverMaxTime: 0
RollbackCount: 0
RollbackTotalTime: 0
RollbackAverageTime: 0
RollbackMaxTime: 0
StartCount: 0
StartTotalTime: 0
StartAverageTime: 0
StartMaxTime: 0
2016-02-28 07:00:00,115 WARN [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool]
(DefaultQuartzScheduler_Worker-1) IJ000621: Destroying connection that could not be
validated: null
2016-02-28 07:00:00,121 WARN
[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener]
(DefaultQuartzScheduler_Worker-1) IJ000305: Connection error occured:
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@6fd4da32[state=NORMAL
managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@202c95de connection
handles=0 lastReturned=1456527600550 lastValidated=1456527600550
lastCheckedOut=1456527600550 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@55209893
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool@2665f4d6[pool=pemain1]
xaResource=XAResourceWrapperImpl@62f34251[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection(a)202c95de
pad=false overrideRmValue=null productName=DB2/NT64 productVersion=SQL09078
jndiName=java:/jdbc/PEMAIN1] txSync=null]:
com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException:
[jcc][t4][2030][11211][4.14.122] A communication error occurred during operations on the
connection's underlying socket, socket input stream,
or socket output stream. Error location: T4Agent.sendRequest() - flush (-1). Message:
Software caused connection abort: socket write error. ERRORCODE=-4499, SQLSTATE=08001
{code}
NPE when validating database connection (and the validation failed)
if connection pool statistics is enabled
------------------------------------------------------------------------------------------------------------
Key: JBJCA-1310
URL:
https://issues.jboss.org/browse/JBJCA-1310
Project: IronJacamar
Issue Type: Bug
Components: Core
Affects Versions: WildFly/IronJacamar 1.3.2.Final, 1.2.6.Final
Reporter: Hugh Nguyen
Assignee: Jesper Pedersen
- An xa-datasource connection pool is configured with: statistic-enabled=true,
validate-on-match=true
- When validation failed, after the failure, the following is logged:
{code}
2016-02-10 12:23:12,580 WARN
[org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (Sched1_Worker-13) IJ000621:
Destroying connection that could not be validated: null
{code}
- This appears to come from SemaphoreConcurrentLinkedDequeManagedConnectionPool.java,
line 436:
{code}
log.destroyingConnectionNotValidated(clw.getConnectionListener());
{code}
- So apparently clw.getConnectionListener() is null at this point, causing line 441/442
to throw NPE, if statistics is enabled:
{code}
pool.getInternalStatistics().deltaTotalPoolTime(lastUsed -
clw.getConnectionListener().getLastReturnedTime());
{code}
- NPE is caught by the catch clause, and line 456 write the following to the log:
{code}
2016-02-10 12:23:12,580 WARN
[org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (Sched1_Worker-13) IJ000613:
Throwable while trying to match managed connection, destroying connection: null:
java.lang.NullPointerException
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:441)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:708)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:607)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:590)
at
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:429)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:747)
{code}
- However, this catch clause try to do the same thing that cause the NPE in line 461/462
{code}
pool.getInternalStatistics().deltaTotalPoolTime(lastUsed -
clw.getConnectionListener().getLastReturnedTime());
{code}
- And finally this NPE is throw all the way out to the user of the connection
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)