inconsistent state after write error during commit

[lpeer...@gmail.com]

Hi,

I originally posted this message to a topic describing how to use xadisk in JBoss (see https://groups.google.com/forum/#!topic/xadisk/soANGGx9xOk), but moved it here as in fact it is (turns out to be) not JBoss related at all.

Here is the original post:

Hi Nitin,

I followed the steps described above on a JBoss (jboss-7.1.0 ) instance 
running on my local windows dev machine, and unexpectedly got this result 
in the log when running the test:

13:01:21,138 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 2) 
JBAS018559: Deployed "XADisk.rar"
13:01:21,139 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 2) 
JBAS018559: Deployed "TestServlet.war"
13:01:21,139 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 2) 
JBAS018559: Deployed "nl-kb-abcstor-ds.xml"
13:01:21,140 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 2) 
JBAS018559: Deployed "abcstor-0.0.1.war"
13:01:28,207 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016037: 
Could not find new XAResource to use for recovering non-serializable 
XAResource XAResourceRecord < resource:null, txid:< formatId=131077, 
gtrid_length=29, bqual_length=36, 
tx_uid=0:ffff0a65160d:16c173ab:528df2d2:d, node_name=1, 
branch_uid=0:ffff0a65160d:16c173ab:528df2d2:12, subordinatenodename=null, 
eis_name=java:/xadiskcf >, heuristic: TwoPhaseOutcome.FINISH_OK, product: 
XADisk/1.0, jndiName: java:/xadiskcf 
com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@2d7dc5a3 >
13:01:28,208 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016038: 
No XAResource to recover < formatId=131077, gtrid_length=29, 
bqual_length=36, tx_uid=0:ffff0a65160d:16c173ab:528df2d2:d, node_name=1, 
branch_uid=0:ffff0a65160d:16c173ab:528df2d2:12, subordinatenodename=null, 
eis_name=java:/xadiskcf >
13:02:01,022 WARN  [com.arjuna.ats.jta] (http--0.0.0.0-8181-1) 
ARJUNA016039: onePhaseCommit on < formatId=131077, gtrid_length=29, 
bqual_length=36, tx_uid=0:ffff0a65160d:533e066:528df60e:15, node_name=1, 
branch_uid=0:ffff0a65160d:533e066:528df60e:17, subordinatenodename=null, 
eis_name=java:/xadiskcf > 
(XAResourceWrapperImpl@11f8c23f[xaResource=org.xadisk.connector.XAResourceImpl@47d30fe0 
pad=false overrideRmValue=false productName=XADisk productVersion=1.0 
jndiName=java:/xadiskcf]) failed with exception XAException.XAER_RMFAIL: 
javax.transaction.xa.XAException
at 
org.xadisk.filesystem.utilities.MiscUtils.createXAExceptionWithCause(MiscUtils.java:18) 
[XADisk.jar:]
at org.xadisk.connector.XAResourceImpl.commit(XAResourceImpl.java:135) 
[XADisk.jar:]
at 
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.commit(XAResourceWrapperImpl.java:90) 
[ironjacamar-core-impl-1.0.7.Final.jar:1.0.7.Final]
at 
com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:667)
at 
com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2283)
at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1466)
at 
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98)
at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164)
at 
com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165)
at 
com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)
at 
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at 
org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:167)
at Servlet1.processRequest(Servlet1.java:29) at 
Servlet1.doGet(Servlet1.java:41) at 
javax.servlet.http.HttpServlet.service(HttpServlet.java:734) 
[jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) 
[jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final]
at 
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) 
[jbossweb-7.0.10.Final.jar:]
at 
org.jboss.modcluster.container.jbossweb.JBossWebContext$RequestListenerValve.event(JBossWebContext.java:67)
at 
org.jboss.modcluster.container.jbossweb.JBossWebContext$RequestListenerValve.invoke(JBossWebContext.java:48)
at 
org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:154) 
[jboss-as-web-7.1.0.Final.jar:7.1.0.Final]
at 
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) 
[jbossweb-7.0.10.Final.jar:]
at 
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:671) 
[jbossweb-7.0.10.Final.jar:]
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:930) 
[jbossweb-7.0.10.Final.jar:]
at java.lang.Thread.run(Thread.java:724) [rt.jar:1.7.0_40]
Caused by: org.xadisk.filesystem.exceptions.TransactionFailedException: The 
transaction has failed and has not completed commit or rollback. The 
file-system data operated on by the transaction may be in inconsistent 
state. This exception is not expected to occur in general, and indicates a 
severe problem.
at org.xadisk.filesystem.NativeSession.commit(NativeSession.java:747) 
[XADisk.jar:]
at org.xadisk.connector.XAResourceImpl.commit(XAResourceImpl.java:131) 
[XADisk.jar:]
... 29 more
Caused by: java.io.IOException: A required privilege is not held by the 
client
at java.io.WinNTFileSystem.createFileExclusively(Native Method) 
[rt.jar:1.7.0_40]
at java.io.File.createNewFile(File.java:1006) [rt.jar:1.7.0_40]
at 
org.xadisk.filesystem.utilities.FileIOUtility.createFile(FileIOUtility.java:86) 
[XADisk.jar:]
at 
org.xadisk.filesystem.DurableDiskSession.createFile(DurableDiskSession.java:158) 
[XADisk.jar:]
at 
org.xadisk.filesystem.NativeSession.commitCreateFile(NativeSession.java:894) 
[XADisk.jar:]
at org.xadisk.filesystem.NativeSession.commit(NativeSession.java:697) 
[XADisk.jar:]
... 30 more

It is true that the root of the c:\ disk is not writable, but that should 
just result in a rollback, shouldn't it ?

I attached the xadisk system dir created after this first run.

Any idea what could be wrong here ?

Regards, Luc.

[lpeer...@gmail.com]

Hi,

After exlpanation by Nitin I think understand better: when errors like 'no permission to write to file' occur, when doing the file handling via XADisk this will be at commit time. At that moment XADisk will not rollback the transaction, but instead signal that something has gone wrong and admin intervention is necessary.

I assume this means that if I want to have a transaction that contains database and file operations and that should fail on conditions like no write permission, I should explicitly check for such conditions in my code and set the rollback flag if applicable ?

Regards, Luc.

[Nitin Verma]

Hi Luc,

One does not need to perform any permission check, xadisk does it by itself. For example, in the current test-case, when you create "C:/test.txt", there is a check whether the directory "C:/" can be written or not:

NativeSession.createFile -> NativeSession.checkPermission -> TransactionVirtualView.isDirectoryWritable(for directory "C:/") -> f.canWrite().

As this test-case is failing later in commit, this is strange, because it means that f.canWrite() over "C:/" is returning true but the file creation for "C:/test.txt" is failing. Can you check the value of f.canWrite() for "C:/" in a simple java test application on this system.

Thanks,
Nitin

[Nitin Verma]

Also copying some details around TransactionFailedException from our email discussion:

"Once xadisk starts committing a transaction, and if there are any unexpected issues it will never revert any changes made during commit (i.e. it won't rollback). It will leave the particular transaction in an inconsistent state requiring user/administrator's intervention. It is expected that the user/admin would resolve the failed transaction (do cleanup etc) (note that one should not call rollback method over xadisk in such a case). XADisk assumes that the error scenarios should not arise in routine and if such error occurs there is something unexpected/uncommon, eg some other application has locked the same file.

Such inconsistent states (failing to complete a transaction) are informed to the application via TransactionFailedException. See https://xadisk.java.net/javadoc/1.2.2/org/xadisk/filesystem/exceptions/TransactionFailedException.html for details."

[lpeer...@gmail.com]

Hi Nitin,

This is the Java code I just ran:

    File f = new File( "C:/");

    System.out.println("f canwrite " + f.canWrite());

    File newFile = new File( f.getAbsolutePath(), "zap.txt");

    boolean created = newFile.createNewFile();

    System.out.println( "created: " + created);

The output:

 f canwrite true

Exception in thread "main" java.io.IOException: A required privilege is not held by the client

at java.io.WinNTFileSystem.createFileExclusively(Native Method)

at java.io.File.createNewFile(File.java:1006)

at zap.main(zap.java:16)

Regards, Luc.

[lpeer...@gmail.com]

Hi Nitin,

Apparently this strange contradictory result can be caused by a Windows misconfiguration:

http://answers.microsoft.com/en-us/windows/forum/windows_vista-security/error-0x80070522-a-required-privilege-is-not-held/78cc11ec-c543-418d-9183-131318e9db8a

Will attempt to apply the steps described there.

Regards, Luc.

[lpeer...@gmail.com]

Hi Nitin,

After disabling the UAC on my computer it works: I can create files on my c:\ disk manually and the testservlet runs (creating an empty test.txt file).

Regards, Luc.

[Nitin Verma]

Hi Luc,

I have filed a tracking bug for this strange behavior, to look for alternatives in such cases. https://java.net/jira/browse/XADISK-153

Can you please provide the exact windows version details.

Thanks,
Nitin

[pjlh...@googlemail.com]

Hi Nitin

I have a question regarding the case you have detailed below, where a commit fails due to an unexpected issue, and the system requires an administrator's intervention.

My understanding is that if the administrator fixes the underlying problem then xadisk will , next time it enters recovery mode for this instance, see the incomplete commit log and continue to commit where it left off.

My problem is that I have 1 instance per JVM in an appserver, so xa disk will only go into recovery mode if I restart my appserver instance. Is this the recommended way to force a recovery for a non-system crash scenario ?

Thanks

Phil

[Nitin Verma]

Hi Phil,

Apart from resolving the underlying cause of failure, the administrator should also mark the transaction as complete (see https://xadisk.java.net/javadoc/1.2.2/org/xadisk/bridge/proxies/interfaces/XAFileSystem.html#declareTransactionAsComplete%28byte[]%29). This mark operation would just mark the transaction as resolved and free xadisk from any further responsibility regarding that transaction. Effectively, xadisk adds a transaction complete log upon such mark operation, and this would save it from trying to attempt that transaction during next recovery, if any. Refer to:
https://xadisk.java.net/javadoc/1.2.2/org/xadisk/filesystem/exceptions/TransactionFailedException.html
https://xadisk.java.net/javadoc/1.2.2/org/xadisk/bridge/proxies/interfaces/XAFileSystem.html#declareTransactionAsComplete%28byte[]%29
https://xadisk.java.net/javadoc/1.2.2/org/xadisk/bridge/proxies/interfaces/XAFileSystem.html#getIdentifiersForFailedTransactions%28%29

Now given this, I think your requirement (second question) regarding initiating a recovery deliberately is not valid. But in general, one can do stop and start an xadisk instance gracefully, see:
https://xadisk.java.net/javadoc/1.2.2/org/xadisk/bridge/proxies/interfaces/XAFileSystem.html#shutdown%28%29
along with the usual process of "booting" as xadisk instance:
https://xadisk.java.net/javadoc/1.2.2/org/xadisk/bridge/proxies/interfaces/XAFileSystemProxy.html#bootNativeXAFileSystem%28org.xadisk.filesystem.standalone.StandaloneFileSystemConfiguration%29

During each start of the instance, it naturally has to go through the "recovery" process (by reading logs from its "home" directory), which may or may not find any todo transactions.

Thanks,
Nitin