Jbtm 3015 #1306

tomjenkinson · 2018-04-24T16:19:34Z

https://issues.jboss.org/browse/JBTM-3015

!RTS !QA_JTS_OPENJDKORB !AS_TESTS !QA_JTA !QA_JTS_JACORB !BLACKTIE !QA_JTS_JDKORB !XTS NO_WIN !MAIN !PERF

…e pool we use the type.toString

tomjenkinson · 2018-04-24T16:22:19Z

@Karm this patch seemed to fix it locally for me

jbosstm-bot · 2018-04-24T16:22:24Z

Started testing this pull request with TOMCAT profile: http://narayanaci1.eng.hst.ams2.redhat.com/job/btny-pulls-narayana/PROFILE=TOMCAT,jdk=jdk8.latest,label=linux/220/

Karm · 2018-04-24T16:49:21Z

@tomjenkinson, it does not help 😞
I can see in the log:

24-Apr-2018 18:37:00.986 WARNING [http-nio-8080-exec-3] org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.setPoolConfig There was an error processing pool config properties.
 java.lang.NoSuchFieldException: maxWaitMillis
      at java.lang.Class.getDeclaredField(Class.java:2070)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.getSetMethod(TransactionalDataSourceFactory.java:226)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.setPoolConfig(TransactionalDataSourceFactory.java:204)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.getObjectInstance(TransactionalDataSourceFactory.java:117)
      <SNAP>

24-Apr-2018 18:37:00.988 WARNING [http-nio-8080-exec-3] org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.setPoolConfig There was an error processing pool config properties.
 java.lang.NoSuchFieldException: testOnBorrow
      at java.lang.Class.getDeclaredField(Class.java:2070)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.getSetMethod(TransactionalDataSourceFactory.java:226)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.setPoolConfig(TransactionalDataSourceFactory.java:204)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.getObjectInstance(TransactionalDataSourceFactory.java:117)
      <SNAP>

24-Apr-2018 18:37:00.991 WARNING [http-nio-8080-exec-3] org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.setPoolConfig There was an error processing pool config properties.
 java.lang.NoSuchFieldException: jmxEnabled
      at java.lang.Class.getDeclaredField(Class.java:2070)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.getSetMethod(TransactionalDataSourceFactory.java:226)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.setPoolConfig(TransactionalDataSourceFactory.java:204)
      at org.jboss.narayana.tomcat.jta.TransactionalDataSourceFactory.getObjectInstance(TransactionalDataSourceFactory.java:117)
      <SNAP>

Despite those being legit props IIUC: GenericObjectPool.java#L462

With your patch applied, I keep seeing endless DB trace:

2018-04-24 16:46:09.859 UTC transaction_id: 0 LOG:  execute <unnamed>: SELECT gid FROM pg_prepared_xacts where database = current_database()

And Tomcat's:

24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run PeriodicRecovery: background thread Status <== SCANNING
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run PeriodicRecovery: background thread scanning
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal Periodic recovery first pass at Tue, 24 Apr 2018 18:47:41
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.periodicWorkFirstPass AtomicActionRecoveryModule first pass
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.processTransactions processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal  
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.setScanState XARecoveryModule state change IDLE->FIRST_PASS

24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass Local XARecoveryModule - first pass
24-Apr-2018 18:47:41.935 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass xarecovery of org.postgresql.xa.PGXAConnection@5f3ec7c3
24-Apr-2018 18:47:41.936 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass Found 0 xids in doubt
24-Apr-2018 18:47:41.936 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass xarecovery of org.jboss.narayana.tomcat.jta.integration.app.TestXAResource@55d171e3
24-Apr-2018 18:47:41.936 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass Found 0 xids in doubt
24-Apr-2018 18:47:41.937 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.setScanState XARecoveryModule state change FIRST_PASS->BETWEEN_PASSES

24-Apr-2018 18:47:41.937 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal  




24-Apr-2018 18:47:43.937 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal Periodic recovery second pass at Tue, 24 Apr 2018 18:47:43
24-Apr-2018 18:47:43.937 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.periodicWorkSecondPass AtomicActionRecoveryModule second pass
24-Apr-2018 18:47:43.937 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal  
24-Apr-2018 18:47:43.937 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.setScanState XARecoveryModule state change BETWEEN_PASSES->SECOND_PASS

24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass Local XARecoveryModule - second pass
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass Local XARecoveryModule.transactionInitiatedRecovery completed
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass xarecovery second pass of org.postgresql.xa.PGXAConnection@5f3ec7c3
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass Have 0 Xids to recover on this pass.
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass xarecovery second pass of org.jboss.narayana.tomcat.jta.integration.app.TestXAResource@55d171e3
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass Have 0 Xids to recover on this pass.
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass Local XARecoveryModule.resourceInitiatedRecovery completed
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.setScanState XARecoveryModule state change SECOND_PASS->IDLE

24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal  
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run PeriodicRecovery: background thread Status <== INACTIVE
24-Apr-2018 18:47:43.938 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run PeriodicRecovery: background thread backing off





24-Apr-2018 18:47:45.939 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run PeriodicRecovery: background thread Status <== SCANNING
24-Apr-2018 18:47:45.939 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run PeriodicRecovery: background thread scanning
24-Apr-2018 18:47:45.939 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal Periodic recovery first pass at Tue, 24 Apr 2018 18:47:45
24-Apr-2018 18:47:45.939 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.periodicWorkFirstPass AtomicActionRecoveryModule first pass
24-Apr-2018 18:47:45.939 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.processTransactions processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
24-Apr-2018 18:47:45.939 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal  
24-Apr-2018 18:47:45.940 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.setScanState XARecoveryModule state change IDLE->FIRST_PASS

24-Apr-2018 18:47:45.940 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass Local XARecoveryModule - first pass
24-Apr-2018 18:47:45.940 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass xarecovery of org.postgresql.xa.PGXAConnection@5f3ec7c3
24-Apr-2018 18:47:45.942 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass Found 0 xids in doubt
24-Apr-2018 18:47:45.942 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass xarecovery of org.jboss.narayana.tomcat.jta.integration.app.TestXAResource@55d171e3
24-Apr-2018 18:47:45.942 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass Found 0 xids in doubt
24-Apr-2018 18:47:45.942 DEBUG [Periodic Recovery] com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.setScanState XARecoveryModule state change FIRST_PASS->BETWEEN_PASSES

24-Apr-2018 18:47:45.942 DEBUG [Periodic Recovery] com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal

Isn't there something missing in the PR?

Config change:

-             tsDbSource.setAttribute("maxTotal", "4");
+            tsDbSource.setAttribute("maxTotal", "20");
....
-         IntStream.range(0, 3).forEach(i -> test(EXECUTOR_URL + RECOVERY_TEST));
+        IntStream.range(0, 10).forEach(i -> test(EXECUTOR_URL + RECOVERY_TEST));

tomjenkinson · 2018-04-24T16:57:22Z

Weird that I did not see it here. I will take a further look

jbosstm-bot · 2018-04-24T17:20:35Z

TOMCAT profile tests passed - Job complete http://narayanaci1.eng.hst.ams2.redhat.com/job/btny-pulls-narayana/PROFILE=TOMCAT,jdk=jdk8.latest,label=linux/220/

zhfeng · 2018-04-25T07:43:41Z

Thanks @tomjenkinson , and it looks good to me.
@Karm In the term of the "NoSuchFieldException", I think there are only "maxTotal", "maxIdle" and "minIdle" in the GenericObjectPoolConfig, the others are in its parent class BaseObjectPoolConfig. I will create another JIRA for fixing.

And there is an issue in the TestExecutor.writeToTheDatabase() which should close the connection at the end. I will open the other PR #1307 for fixing this issue.

jbosstm-bot · 2020-03-19T14:51:32Z

BLACKTIE profile tests failed on Linux (https://ci-master-jenkins-csb-narayana.cloud.paas.psi.redhat.com/job/btny-pulls-narayana/PROFILE=BLACKTIE,jdk=jdk8.latest,label=swarm/588/): Narayana rebase on master failed. Please rebase it manually

jbosstm-bot · 2020-03-19T14:51:32Z

MAIN profile tests failed (https://ci-master-jenkins-csb-narayana.cloud.paas.psi.redhat.com/job/btny-pulls-narayana/PROFILE=MAIN,jdk=jdk8.latest,label=swarm/588/): Narayana rebase on master failed. Please rebase it manually

JBTM-3015 Make sure that when looking for the properties to set on th…

96c3e14

…e pool we use the type.toString

tomjenkinson requested a review from zhfeng April 24, 2018 16:20

tomjenkinson mentioned this pull request Apr 24, 2018

[JWS-883] not throwing NPE when wrong db test type is provided #1305

Merged

tomjenkinson requested a review from ochaloup April 24, 2018 16:28

zhfeng approved these changes Apr 25, 2018

View reviewed changes

tomjenkinson merged commit 83ee12f into jbosstm:master Apr 25, 2018

tomjenkinson mentioned this pull request Apr 25, 2018

JBTM-3015 Fix the TestExecutor to close the connection at the end of test #1307

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Jbtm 3015 #1306

Jbtm 3015 #1306

tomjenkinson commented Apr 24, 2018

tomjenkinson commented Apr 24, 2018

jbosstm-bot commented Apr 24, 2018

Karm commented Apr 24, 2018 •

edited

Loading

tomjenkinson commented Apr 24, 2018

jbosstm-bot commented Apr 24, 2018

zhfeng commented Apr 25, 2018 •

edited

Loading

jbosstm-bot commented Mar 19, 2020

jbosstm-bot commented Mar 19, 2020

Jbtm 3015 #1306

Jbtm 3015 #1306

Conversation

tomjenkinson commented Apr 24, 2018

tomjenkinson commented Apr 24, 2018

jbosstm-bot commented Apr 24, 2018

Karm commented Apr 24, 2018 • edited Loading

tomjenkinson commented Apr 24, 2018

jbosstm-bot commented Apr 24, 2018

zhfeng commented Apr 25, 2018 • edited Loading

jbosstm-bot commented Mar 19, 2020

jbosstm-bot commented Mar 19, 2020

Karm commented Apr 24, 2018 •

edited

Loading

zhfeng commented Apr 25, 2018 •

edited

Loading