SP-73 BIS-21 multiple recovery checkpoint hit in one registration

SVN: 25398

datastore_server/source/java/ch/systemsx/cisd/etlserver/registrator/api/v2/JythonTopLevelDataSetHandlerV2.java

@@ -232,10 +232,12 @@ public class JythonTopLevelDataSetHandlerV2<T extends DataSetInformation> extend
                                     // count
                                     // FIXME: is this safe operation (how to assure, that it won't
                                     // corrupt the recoveryMarkerFile?)
-
-                                    recoveryInfo.increaseTryCount();
-                                    recoveryInfo.setLastTry(new Date());
-                                    recoveryInfo.writeToFile(recoveryMarkerFile);
+                                    DataSetStorageRecoveryInfo rInfo =
+                                            state.getGlobalState().getStorageRecoveryManager()
+                                                    .getRecoveryFileFromMarker(recoveryMarkerFile);
+                                    rInfo.increaseTryCount();
+                                    rInfo.setLastTry(new Date());
+                                    rInfo.writeToFile(recoveryMarkerFile);
                                 }
                             }
                             return true;
@@ -335,7 +337,14 @@ public class JythonTopLevelDataSetHandlerV2<T extends DataSetInformation> extend
 
             if (recoveryStage.beforeOrEqual(RecoveryStage.PRECOMMIT))
             {
-                TechId registrationId = ((DataSetStoragePrecommitRecoveryState<T>)recoveryState).getRegistrationId();
+                TechId registrationId =
+                        ((DataSetStoragePrecommitRecoveryState<T>) recoveryState)
+                                .getRegistrationId();
+                if (registrationId == null)
+                {
+                    throw new IllegalStateException(
+                            "Recovery state cannot have null registrationId at the precommit phase");
+                }
                 entityOperationsSucceeded =
                         state.getGlobalState().getOpenBisService()
                                 .didEntityOperationsSucceed(registrationId);
@@ -377,12 +386,12 @@ public class JythonTopLevelDataSetHandlerV2<T extends DataSetInformation> extend
 
                 operationLog
                         .info("Recovery has found datasets in the AS. The registration of metadata was successful.");
-                
-                if (recoveryStage.beforeOrEqual(RecoveryStage.POST_REGISTRATION_HOOK_EXECUTED)){
+
+                if (recoveryStage.before(RecoveryStage.POST_REGISTRATION_HOOK_EXECUTED))
+                {
                     runner.postRegistration();
                 }
-                
-                
+
                 boolean success = runner.storeAfterRegistration(recoveryStage);
                 if (success)
                 {

datastore_server/sourceTest/java/ch/systemsx/cisd/etlserver/registrator/JythonDropboxRecoveryTest.java

@@ -480,7 +480,7 @@ public class JythonDropboxRecoveryTest extends AbstractJythonDataSetHandlerTest
 
     // INFO: test with recovery from error in storage confirmed
     @Test
-    public void testRecoveryOriginalFailureAtStorageConfirmed()
+    public void testRecoveryFailureAtStorageConfirmed()
     {
         RecoveryTestCase testCase = new RecoveryTestCase("No name");
         setUpHomeDataBaseExpectations();
@@ -501,16 +501,12 @@ public class JythonDropboxRecoveryTest extends AbstractJythonDataSetHandlerTest
 
         handler.handle(markerFile);
 
-        JythonHookTestTool jythonHookTestTool =
-                JythonHookTestTool.createFromWorkingDirectory(workingDirectory);
-        // the check from the original registration
-        jythonHookTestTool.assertLogged("pre_metadata_registration");
-
-        jythonHookTestTool.assertLogged("post_metadata_registration");
+        JythonHookTestTool.assertMessagesInWorkingDirectory(workingDirectory,
+                "pre_metadata_registration", "post_metadata_registration");
 
         assertStorageProcess(atomicatOperationDetails.recordedObject(), DATA_SET_CODE,
                 "sub_data_set_1", 0);
-        
+
         setTheRecoveryInfo(testCase.recoveryRertyCount, testCase.recoveryLastTry);
 
         assertRecoveryFile(testCase.recoveryRertyCount, RecoveryInfoDateConstraint.ORIGINAL,
@@ -527,9 +523,97 @@ public class JythonDropboxRecoveryTest extends AbstractJythonDataSetHandlerTest
         // // item in store
         //
         //
-        // // the hooks after successful registration
-        // jythonHookTestTool.assertLogged("post_storage");
+        JythonHookTestTool.assertMessagesInWorkingDirectory(workingDirectory, "post_storage");
+
+    }
+
+    /**
+     * This tests the registration with adventure, where the failure and recovery happens at every
+     * possible step.
+     */
+    @Test
+    public void testRecoveryAtMultipleCheckpoints()
+    {
+        RecoveryTestCase testCase = new RecoveryTestCase("No name");
+        setUpHomeDataBaseExpectations();
+
+        createData();
+
+        Properties properties =
+                createThreadPropertiesRelativeToScriptsFolder(testCase.dropboxScriptPath,
+                        testCase.overrideProperties);
+
+        createHandler(properties, true, false);
+
+        final RecordingMatcher<ch.systemsx.cisd.openbis.generic.shared.dto.AtomicEntityOperationDetails> atomicatOperationDetails =
+                new RecordingMatcher<ch.systemsx.cisd.openbis.generic.shared.dto.AtomicEntityOperationDetails>();
+
+        // create expectations
+        context.checking(new MultipleErrorsExpectations(atomicatOperationDetails));
+
+        handler.handle(markerFile);
+        setTheRecoveryInfo(testCase.recoveryRertyCount, testCase.recoveryLastTry);
+
+        // now we have registered, but error was thrown from registration
+        JythonHookTestTool.assertMessagesInWorkingDirectory(workingDirectory,
+                "pre_metadata_registration");
+
+        handler.handle(markerFile);
+        setTheRecoveryInfo(testCase.recoveryRertyCount, testCase.recoveryLastTry);
 
+        // now we know we have registered, post_registration_hook executed, but storage failed.
+        JythonHookTestTool.assertMessagesInWorkingDirectory(workingDirectory,
+                "post_metadata_registration");
+
+        // so make filesystem avaiable this time
+        makeFileSystemAvailable(workingDirectory);
+
+        handler.handle(markerFile);
+        setTheRecoveryInfo(testCase.recoveryRertyCount, testCase.recoveryLastTry);
+        // now the storage has succeeded, but storage confirmation has not.
+
+        handler.handle(markerFile);
+//        setTheRecoveryInfo(testCase.recoveryRertyCount, testCase.recoveryLastTry);
+        // now the storage confirmation has succeeded
+        assertStorageProcess(atomicatOperationDetails.recordedObject(), DATA_SET_CODE,
+                "sub_data_set_1", 0);
+
+        assertNoOriginalMarkerFileExists();
+        assertNoRecoveryMarkerFile();
+
+        //
+        // // item in store
+        //
+        //
+        JythonHookTestTool.assertMessagesInWorkingDirectory(workingDirectory, "post_storage");
+
+    }
+
+    class MultipleErrorsExpectations extends AbstractExpectations
+    {
+        public MultipleErrorsExpectations(
+                final RecordingMatcher<AtomicEntityOperationDetails> atomicatOperationDetails)
+        {
+            super(atomicatOperationDetails);
+            prepareExpectations();
+        }
+
+        private void prepareExpectations()
+        {
+            initialExpectations();
+            // first try - fail at registration
+            registerDataSetsAndThrow(true);
+
+            // second handle - fail at storage
+            one(openBisService).didEntityOperationsSucceed(with(any(TechId.class)));
+            will(doAll(makeFileSystemUnavailableAction(), returnValue(true)));
+
+            // third try - fail at storage confirmation
+            setStorageConfirmed(true);
+
+            // fourth try - success
+            setStorageConfirmed(false);
+        }
     }
 
     class StorageConfirmedErrorExpectations extends AbstractExpectations

datastore_server/sourceTest/java/ch/systemsx/cisd/etlserver/registrator/JythonHookTestTool.java

@@ -70,22 +70,36 @@ public class JythonHookTestTool
         }
     }
 
+    /**
+     * Assert that the provided messages has been logged and nothign else. Clears the log file
+     * afterwards.
+     */
+    public static void assertMessagesInWorkingDirectory(File workingDirectory, String... messages)
+    {
+        JythonHookTestTool instance = createFromWorkingDirectory(workingDirectory);
+        for (String message : messages)
+        {
+            instance.assertLogged(message);
+        }
+        instance.assertNoMoreMessages();
+        instance.logFile.delete();
+    }
+
     /**
      * The factory method to create util
      * 
-     * @param incoming - the logical or original incoming available from the
-     *            dropbox
+     * @param incoming - the logical or original incoming available from the dropbox
      */
     public static JythonHookTestTool createFromIncoming(File incoming)
     {
         File workingDirectory;
         if (incoming.getParentFile().getParentFile().getName().equals("pre-staging"))
         {
-            //prestaging
+            // prestaging
             workingDirectory = incoming.getParentFile().getParentFile().getParentFile();
         } else
         {
-            //incoming
+            // incoming
             workingDirectory = incoming.getParentFile();
         }
         return new JythonHookTestTool(workingDirectory);
@@ -144,9 +158,6 @@ public class JythonHookTestTool
     {
         if (lineNumber < originalFileContents.length)
         {
-            for (String s: originalFileContents)
-            System.out.println(s);
-            
             throw new AssertionError("Unexpected message in jython hook test."
                     + originalFileContents[lineNumber]);
         }