[jbossts-issues] [JBoss JIRA] (JBTM-2159) It is possible for the CommitMarkableResource recovery manager to attempt to activate an AtomicAction while it is being committed which can cause filenotfoundstacktrace and NullPointerException

Tom Jenkinson (JIRA) issues at jboss.org
Mon Apr 28 03:10:33 EDT 2014 

    [ https://issues.jboss.org/browse/JBTM-2159?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12963991#comment-12963991 ] 

Tom Jenkinson edited comment on JBTM-2159 at 4/28/14 3:09 AM:
--------------------------------------------------------------

Yeah, it was a race condition but it turns out it only is known to affect CommitMarkableResources, I raised a PR for it over https://github.com/jbosstm/narayana/pull/644/files. I will update the subject. It fixes the NPE.

The thing I am not sure of is how the FileNotFoundException could be possible. When I look into the file locking code, when we delete the file on disk it should have a read lock, read_state should aquire a read lock on the file and if it can't it should have a null fd: https://github.com/tomjenkinson/narayana/blob/BZ1089251/ArjunaCore/arjuna/classes/com/arjuna/ats/internal/arjuna/objectstore/ShadowingStore.java#L398
                
      was (Author: tomjenkinson):
    Yeah, it was a race condition but it turns out it only is known to affect CommitMarkableResources, I raised a PR for it over here. I will update the subject.
                  
> It is possible for the CommitMarkableResource recovery manager to attempt to activate an AtomicAction while it is being committed which can cause filenotfoundstacktrace and NullPointerException
> -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: JBTM-2159
>                 URL: https://issues.jboss.org/browse/JBTM-2159
>             Project: JBoss Transaction Manager
>          Issue Type: Enhancement
>      Security Level: Public(Everyone can see) 
>          Components: Recovery
>            Reporter: Tom Jenkinson
>            Assignee: Tom Jenkinson
>
> Basically:
> 1. App thread creates AA
> 2. AA UID is seen in phase1 recovery thread by CommitMarkableResourceRecoveryModule
> 3. App thread commits AA
> 4. App thread deletes AA UID
> 5. Recovery thread tries to activate AA with UID in CommitMarkableResourceRecoveryModule but it gets exceptions as shown here: 
> 12:23:07 12:23:07,915 WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) Could not query objectstore: : java.io.IOException: java.lang.NullPointerException
> 12:23:07 	at com.arjuna.ats.arjuna.StateManager.unpackHeader(StateManager.java:732) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 12:23:07 	at com.arjuna.ats.internal.jta.recovery.arjunacore.RecoverConnectableAtomicAction.<init>(RecoverConnectableAtomicAction.java:52) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 12:23:07 	at com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule.periodicWorkFirstPass(CommitMarkableResourceRecordRecoveryModule.java:379) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 12:23:07 	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:743) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 12:23:07 	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 12:23:07 Caused by: java.lang.NullPointerException
> 12:23:07 	at com.arjuna.ats.arjuna.StateManager.unpackHeader(StateManager.java:697) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 12:23:07 	... 4 more
> 12:23:07 
> 15:16:36 15:16:36,247 WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) Could not query objectstore: : com.arjuna.ats.arjuna.exceptions.ObjectStoreException: ShadowingStore::read_state error: java.io.FileNotFoundException: /tmp/activemq-soak/ibm-mq-testsuite/src/test/config/activemq/install/target/jboss-eap/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/0_ffff0a106418_-2b02421b_534ffd61_4c1764 (No such file or directory)
> 15:16:36 	at com.arjuna.ats.internal.arjuna.objectstore.ShadowingStore.read_state(ShadowingStore.java:412) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 	at com.arjuna.ats.internal.arjuna.objectstore.FileSystemStore.read_committed(FileSystemStore.java:98) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 	at com.arjuna.ats.internal.jta.recovery.arjunacore.RecoverConnectableAtomicAction.<init>(RecoverConnectableAtomicAction.java:48) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 	at com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule.periodicWorkFirstPass(CommitMarkableResourceRecordRecoveryModule.java:379) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:743) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 Caused by: java.io.FileNotFoundException: /tmp/activemq-soak/ibm-mq-testsuite/src/test/config/activemq/install/target/jboss-eap/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/0_ffff0a106418_-2b02421b_534ffd61_4c1764 (No such file or directory)
> 15:16:36 	at java.io.FileInputStream.open(Native Method) [rt.jar:1.7.0_51]
> 15:16:36 	at java.io.FileInputStream.<init>(FileInputStream.java:146) [rt.jar:1.7.0_51]
> 15:16:36 	at com.arjuna.ats.internal.arjuna.objectstore.ShadowingStore.read_state(ShadowingStore.java:406) [jbossjts-jacorb-4.17.18.Final-redhat-1.jar:4.17.18.Final-redhat-1]
> 15:16:36 	... 5 more
> 15:16:36 

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

More information about the jbossts-issues mailing list