[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd updated WFLY-7835:
------------------------------
Involved: Viacheslav Astapkovich, Vsevolod Golovanov, Vsevolod Golovanov (was: Viacheslav Astapkovich)
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: EJB, Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
> Attachments: log-fragment-7835
>
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> {quote}
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> {quote}
> this event seems not interest.
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> {code}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {code}
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd updated WFLY-7835:
------------------------------
Description:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
{quote}
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
{quote}
this event seems not interest.
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
{code}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{code}
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
was:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
{quote}
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
{quote}
this event seems not interest.
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
> Attachments: log-fragment-7835
>
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> {quote}
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> {quote}
> this event seems not interest.
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> {code}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {code}
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd updated WFLY-7835:
------------------------------
Description:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
{quote}
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
{quote}
this event seems not interest.
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
was:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
> Attachments: log-fragment-7835
>
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> {quote}
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> {quote}
> this event seems not interest.
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd updated WFLY-7835:
------------------------------
Description:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
was:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
> Attachments: log-fragment-7835
>
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner). This event not catched in logfile, because regular behavour not logged.
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd commented on WFLY-7835:
-----------------------------------
full log in log-fragment-7835
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
> Attachments: log-fragment-7835
>
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd updated WFLY-7835:
------------------------------
Attachment: log-fragment-7835
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
> Attachments: log-fragment-7835
>
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
[ https://issues.jboss.org/browse/WFLY-7835?page=com.atlassian.jira.plugin.... ]
kostd kostd updated WFLY-7835:
------------------------------
Description:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
was:
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null (?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
> StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
> --------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-7835
> URL: https://issues.jboss.org/browse/WFLY-7835
> Project: WildFly
> Issue Type: Bug
> Components: Transactions
> Affects Versions: 10.0.0.Final
> Environment: wildfly 10.0.0.Final
> java 8u101
> narayana-jts-integration-5.2.12.Final
> SFSB with CMT
> Reporter: kostd kostd
> Assignee: Tom Jenkinson
> Priority: Minor
>
> full log will be attached, now short chronology:
> 1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
> So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
> 2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null ( ?):
> {quote}
> 02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
> {quote}
> 3. 02:39:32: query timeout in task thread reached:
> 02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
> 4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
> {quote}
> 02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
> {quote}
> 5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
> {quote}
> 02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
> {quote}
> 6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
> {quote}
> 02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
> {quote}
> So, next two clauses is bug-behavour or by-desighn behavour:
> c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
> c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
> ?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (WFLY-7835) StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
by kostd kostd (JIRA)
kostd kostd created WFLY-7835:
---------------------------------
Summary: StatefulSessionSynchronizationInterceptor can`t see that current tx replaced by arjuna`s tx reaper and can`t aquire it`s own component lock
Key: WFLY-7835
URL: https://issues.jboss.org/browse/WFLY-7835
Project: WildFly
Issue Type: Bug
Components: Transactions
Affects Versions: 10.0.0.Final
Environment: wildfly 10.0.0.Final
java 8u101
narayana-jts-integration-5.2.12.Final
SFSB with CMT
Reporter: kostd kostd
Assignee: Tom Jenkinson
Priority: Minor
full log will be attached, now short chronology:
1. ~02:20 default task-186 starts request processing. During request where was call to ExtendedPersistenceContainer (SFSB with CMT).
So StatefulSessionSynchronizationInterceptor#processInvocation called and component lock aquired (owner = current tx, see StatefulSessionSynchronizationInterceptor#getLockOwner)
2. 02:39:26: tx timeout reached (20min), so arjuna`s reaper thread trying cancel tx. Now current tx == null (?):
{quote}
02:39:26,882 WARN [arjuna] (Transaction Reaper Worker 73) ARJUNA012381: Action id 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c completed with multiple threads - thread default task-186 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
{quote}
3. 02:39:32: query timeout in task thread reached:
02:39:32,806 ERROR [sql] (default task-186) SQL query error: 2c344b99 (executed in 1 205 917 ms): java.sql.SQLTimeoutException: ORA-01013: пользователем запрошена отмена текущей операции
4. 02:39:32: arjuna`s reaper thread trying to release component lock but fails because does not own`em:
{quote}
02:39:32,808 WARN [txn] (Transaction Reaper Worker 73) WFLYTX0027: The pre-jca synchronization org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@58e72087 associated with tx TransactionImple < ac, BasicAction: 0:ffff0aa010c9:22fba49e:5848e8ad:446f10c status: ActionStatus.ABORTED > failed during after completion: java.lang.IllegalMonitorStateException
{quote}
5. 02:39: task-thread contiunes request processing: hibernate noticed that current tx replaced(removed) by arjuna`s reaper:
{quote}
02:39:32,822 WARN [lifecycle] (default task-186) #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!: javax.faces.FacesException: #{viewModel.save}: javax.persistence.PersistenceException: org.hibernate.HibernateException: Transaction was rolled back in a different thread!
{quote}
6. but StatefulSessionSynchronizationInterceptor not noticed. StatefulSessionSynchronizationInterceptor trying to aquire same lock, but owner changed, was current tx and now current thread (?):
{quote}
02:39:37,827 ERROR [invocation] (default task-186) WFLYEJB0034: EJB Invocation failed on component ExtendedPersistenceContainer for method public javax.persistence.EntityManager ru.argustelecom.system.inf.transaction.ExtendedPersistenceContainer.getEntityManager(): javax.ejb.ConcurrentAccessTimeoutException: WFLYEJB0228: EJB 3.1 FR 4.3.14.1 concurrent access timeout on ExtendedPersistenceContainer - could not obtain lock within 5000 MILLISECONDS
{quote}
So, next two clauses is bug-behavour or by-desighn behavour:
c1. arjuna`s reaper thread trying release component lock through StatefulSessionSynchronizationInterceptor, but does not owns this lock.
c2. StatefulSessionSynchronizationInterceptor can`t see that current tx replaced and trying to aquire it`s own component lock with different owners. In second try lock cannot be aquired during any timeout
?
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (JGRP-2135) OOM with JGroups 3.6.11.
by Bela Ban (JIRA)
[ https://issues.jboss.org/browse/JGRP-2135?page=com.atlassian.jira.plugin.... ]
Bela Ban commented on JGRP-2135:
--------------------------------
I thought about adding a max_msg_size attribute to TCP, but didn't do it because this is a band-aid over some root cause that needs to be discovered.
I'd rather like to find out what the root cause is.
> OOM with JGroups 3.6.11.
> ------------------------
>
> Key: JGRP-2135
> URL: https://issues.jboss.org/browse/JGRP-2135
> Project: JGroups
> Issue Type: Bug
> Affects Versions: 3.6.11
> Reporter: Zoltan Farkas
> Assignee: Bela Ban
> Fix For: 3.6.12
>
>
> We are running our JVMs with : -XX:OnOutOfMemoryError="kill -9 %p"
> we have been experiencing OOMs fairly often, and the OOMs happen at:
> {code}
> Object / Stack Frame |Name | Shallow Heap | Retained Heap |Context Class Loader |Is Daemon
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> java.lang.Thread @ 0x81bdf838 |Connection.Receiver [144.77.77.53:50363 - 144.77.77.53:50363],sis-cluster.service,prodpmwsv5-6461| 120 | 456 |sun.misc.Launcher$AppClassLoader @ 0x800175a8|false
> |- at java.lang.OutOfMemoryError.<init>()V (OutOfMemoryError.java:48) | | | | |
> |- at org.jgroups.blocks.cs.TcpConnection$Receiver.run()V (TcpConnection.java:310)| | | | |
> |- at java.lang.Thread.run()V (Thread.java:745) | | | | |
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> {code}
> the Code where it happens is in TcpConnection.java:
> {code}
> while(canRun()) {
> try {
> int len=in.readInt();
> if(buffer == null || buffer.length < len)
> buffer=new byte[len];
> in.readFully(buffer, 0, len);
> updateLastAccessed();
> server.receive(peer_addr, buffer, 0, len);
> }
> catch(OutOfMemoryError mem_ex) {
> t=mem_ex;
> break; // continue;
> }
> catch(IOException io_ex) {
> t=io_ex;
> break;
> }
> catch(Throwable e) {
> }
> }
> {code}
> when allocating: buffer=new byte[len];
> it looks to me that some invalid large value is received and the process OOMs when allocating a huge byte array
> Running JVMs without kill on OOM would make this issue "dissapear" in the sense that it is swallowed by:
> {code}
> catch(OutOfMemoryError mem_ex) {
> t=mem_ex;
> break; // continue;
> }
> {code}
> Handling OutOfMemoryError is a strange implementation choice...
> instead a size limit should be employed to protect from receiving invalid sizes...
> My heap limit is 1GB and my heap dumps are 50Mb so the attempted allocation size is huge...
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months
[JBoss JIRA] (JGRP-2135) OOM with JGroups 3.6.11.
by Zoltan Farkas (JIRA)
[ https://issues.jboss.org/browse/JGRP-2135?page=com.atlassian.jira.plugin.... ]
Zoltan Farkas commented on JGRP-2135:
-------------------------------------
Hi Bela, I patched the lib like:
{code}
private static final int MAX_MESSAGE_SIZE = Integer.getInteger("jgroups.maxMessageSize", 1048576);
public void run() {
Throwable t=null;
while(canRun()) {
try {
int len=in.readInt();
if (len > MAX_MESSAGE_SIZE || len < 0) {
t = new IOException("Received message size invalid " + len);
in.close();
break;
}
if(buffer == null || buffer.length < len)
buffer=new byte[len];
in.readFully(buffer, 0, len);
updateLastAccessed();
server.receive(peer_addr, buffer, 0, len);
} catch(IOException io_ex) {
t=io_ex;
break;
}
}
server.notifyConnectionClosed(TcpConnection.this, String.format(Locale.US, "%s: %s", getClass().getSimpleName(),
t != null? t.toString() : "n/a"));
}
{code}
I am not sure where the invalid message sizes were coming, but this stopped my processes from crashing...
I find this a better solution than catching OOM...
Reliably recovering from OOM is impossible... which is why we run our processes with "kill on OOM"
> OOM with JGroups 3.6.11.
> ------------------------
>
> Key: JGRP-2135
> URL: https://issues.jboss.org/browse/JGRP-2135
> Project: JGroups
> Issue Type: Bug
> Affects Versions: 3.6.11
> Reporter: Zoltan Farkas
> Assignee: Bela Ban
> Fix For: 3.6.12
>
>
> We are running our JVMs with : -XX:OnOutOfMemoryError="kill -9 %p"
> we have been experiencing OOMs fairly often, and the OOMs happen at:
> {code}
> Object / Stack Frame |Name | Shallow Heap | Retained Heap |Context Class Loader |Is Daemon
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> java.lang.Thread @ 0x81bdf838 |Connection.Receiver [144.77.77.53:50363 - 144.77.77.53:50363],sis-cluster.service,prodpmwsv5-6461| 120 | 456 |sun.misc.Launcher$AppClassLoader @ 0x800175a8|false
> |- at java.lang.OutOfMemoryError.<init>()V (OutOfMemoryError.java:48) | | | | |
> |- at org.jgroups.blocks.cs.TcpConnection$Receiver.run()V (TcpConnection.java:310)| | | | |
> |- at java.lang.Thread.run()V (Thread.java:745) | | | | |
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> {code}
> the Code where it happens is in TcpConnection.java:
> {code}
> while(canRun()) {
> try {
> int len=in.readInt();
> if(buffer == null || buffer.length < len)
> buffer=new byte[len];
> in.readFully(buffer, 0, len);
> updateLastAccessed();
> server.receive(peer_addr, buffer, 0, len);
> }
> catch(OutOfMemoryError mem_ex) {
> t=mem_ex;
> break; // continue;
> }
> catch(IOException io_ex) {
> t=io_ex;
> break;
> }
> catch(Throwable e) {
> }
> }
> {code}
> when allocating: buffer=new byte[len];
> it looks to me that some invalid large value is received and the process OOMs when allocating a huge byte array
> Running JVMs without kill on OOM would make this issue "dissapear" in the sense that it is swallowed by:
> {code}
> catch(OutOfMemoryError mem_ex) {
> t=mem_ex;
> break; // continue;
> }
> {code}
> Handling OutOfMemoryError is a strange implementation choice...
> instead a size limit should be employed to protect from receiving invalid sizes...
> My heap limit is 1GB and my heap dumps are 50Mb so the attempted allocation size is huge...
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
9 years, 4 months