Fix a whole wad of Resume issues and add a bunch of diagnostic logging for FlowHead problems etc

pom.xml

@@ -69,7 +69,7 @@
         <workflow-support-plugin.version>2.17</workflow-support-plugin.version>
         <scm-api-plugin.version>2.0.8</scm-api-plugin.version>
         <groovy-cps.version>1.24</groovy-cps.version>
-        <jenkins-test-harness.version>2.33</jenkins-test-harness.version>
+        <jenkins-test-harness.version>2.37</jenkins-test-harness.version>
     </properties>
     <dependencies>
         <dependency>
@@ -141,7 +141,7 @@
         <dependency>
             <groupId>org.jenkins-ci.plugins.workflow</groupId>
             <artifactId>workflow-job</artifactId>
-            <version>2.18-20180329.215807-4</version>
+            <version>2.18-20180406.172304-8</version>
             <scope>test</scope>
         </dependency>
         <dependency>

src/main/java/org/jenkinsci/plugins/workflow/cps/CpsFlowExecution.java

@@ -316,7 +316,7 @@ public class CpsFlowExecution extends FlowExecution implements BlockableResume {
      * {@link FlowExecution} gets loaded into memory for the build records that have been completed,
      * and for those we don't want to load the program state, so that check should be efficient.
      */
-    Boolean done; // Only non-private for unit test use.
+    boolean done; // Only non-private for unit test use.
 
     /**
      * Groovy compiler with CPS+sandbox transformation correctly setup.
@@ -728,7 +728,7 @@ public void onLoad(FlowExecutionOwner owner) throws IOException {
                         LOGGER.log(Level.WARNING, "Pipeline state not properly persisted, cannot resume "+owner.getUrl());
                         throw new IOException("Cannot resume build -- was not cleanly saved when Jenkins shut down.");
                     }
-                } else if (done == Boolean.TRUE && !super.isComplete()) {
+                } else if (done && !super.isComplete()) {
                     LOGGER.log(Level.WARNING, "Completed flow without FlowEndNode: "+this+" heads:"+getHeadsAsString());
                 }
             } catch (Exception e) {  // Multicatch ensures that failure to load does not nuke the master
@@ -820,7 +820,6 @@ private void loadProgramFailed(final Throwable problem, SettableFuture<CpsThread
             } else {
                 head = getFirstHead();
             }
-            done = Boolean.TRUE;
         }
 
         if (head==null) {
@@ -857,13 +856,12 @@ private void loadProgramFailed(final Throwable problem, SettableFuture<CpsThread
     /** Report a fatal error in the VM. */
     void croak(Throwable t) {
         setResult(Result.FAILURE);
-        done = Boolean.TRUE;
         onProgramEnd(new Outcome(null, t));
         cleanUpHeap();
         try {
             saveOwner();
         } catch (Exception ex) {
-            LOGGER.log(Level.WARNING, "Failed to persist WorkflowRun after noting a serious failure for run:", owner);
+            LOGGER.log(Level.WARNING, "Failed to persist WorkflowRun after noting a serious failure for run: " + owner, ex);
         }
     }
 
@@ -1193,7 +1191,7 @@ public static void maybeAutoPersistNode(@Nonnull FlowNode node) {
     @Override
     @SuppressFBWarnings(value = "RC_REF_COMPARISON_BAD_PRACTICE_BOOLEAN", justification = "We want to explicitly check for boolean not-null and true")
     public boolean isComplete() {
-        return done == Boolean.TRUE || super.isComplete(); // Compare to Boolean.TRUE so null == false.
+        return done || super.isComplete(); // Compare to Boolean.TRUE so null == false.
     }
 
     /**
@@ -1207,18 +1205,24 @@ synchronized void onProgramEnd(Outcome outcome) {
         }
 
         // shrink everything into a single new head
-        done = Boolean.TRUE;
-        if (heads != null) {
-            FlowHead first = getFirstHead();
-            first.setNewHead(head);
-            heads.clear();
-            heads.put(first.getId(), first);
-
-            String tempIotaStr = Integer.toString(this.iota.get());
-            FlowHead lastHead = heads.get(first.getId());
-            if (lastHead == null || lastHead.get() == null || !(lastHead.get().getId().equals(tempIotaStr))) {
-                LOGGER.log(Level.WARNING, "Invalid final head for execution "+this.owner+" with head: "+lastHead);
+        try {
+            if (heads != null) {
+                FlowHead first = getFirstHead();
+                first.setNewHead(head);
+                done = Boolean.TRUE;  // After setting the final head
+                heads.clear();
+                heads.put(first.getId(), first);
+
+                String tempIotaStr = Integer.toString(this.iota.get());
+                FlowHead lastHead = heads.get(first.getId());
+                if (lastHead == null || lastHead.get() == null || !(lastHead.get().getId().equals(tempIotaStr))) {
+                    // Warning of problems with the final call to FlowHead.setNewHead
+                    LOGGER.log(Level.WARNING, "Invalid final head for execution "+this.owner+" with head: "+lastHead);
+                }
             }
+        } catch (Exception ex) {
+            done = Boolean.TRUE;
+            throw ex;
         }
 
         try {
@@ -1566,9 +1570,7 @@ public void marshal(Object source, HierarchicalStreamWriter w, MarshallingContex
                 for (BlockStartNode st : e.startNodes) {
                     writeChild(w, context, "start", st.getId(), String.class);
                 }
-                if (e.done != null) {
-                    writeChild(w, context, "done", e.done, Boolean.class);
-                }
+                writeChild(w, context, "done", e.done, Boolean.class);
             }
             writeChild(w, context, "resumeBlocked", e.resumeBlocked, Boolean.class);
 
@@ -1818,6 +1820,13 @@ private void checkpoint() {
         boolean persistOk = true;
         FlowNodeStorage storage = getStorage();
         if (storage != null) {
+            try { // Node storage must be flushed first so program can be restored
+                storage.flush();
+            } catch (IOException ioe) {
+                persistOk=false;
+                LOGGER.log(Level.WARNING, "Error persisting FlowNode storage before shutdown", ioe);
+            }
+
             // Try to ensure we've saved the appropriate things -- the program is the last stumbling block.
             try {
                 final SettableFuture<Void> myOutcome = SettableFuture.create();
@@ -1849,13 +1858,6 @@ public void onFailure(Throwable t) {
                 persistOk = false;
                 LOGGER.log(Level.FINE, "Error saving program, that should be handled elsewhere.", ex);
             }
-
-            try {
-                storage.flush();
-            } catch (IOException ioe) {
-                persistOk=false;
-                LOGGER.log(Level.WARNING, "Error persisting FlowNode storage before shutdown", ioe);
-            }
             persistedClean = persistOk;
             saveOwner();
         }

src/main/java/org/jenkinsci/plugins/workflow/cps/CpsStepContext.java

@@ -534,9 +534,12 @@ synchronized boolean switchToAsyncMode() {
                 @Override public void onSuccess(CpsThreadGroup result) {
                     try {
                         // TODO keep track of whether the program was saved anyway after saveState was called but before now, and do not bother resaving it in that case
-                        result.saveProgram();
+                        if (result.getExecution().getDurabilityHint().isPersistWithEveryStep()) {
+                            result.getExecution().getStorage().flush();
+                            result.saveProgram();
+                        }
                         f.set(null);
-                    } catch (IOException x) {
+                    } catch (Exception x) {
                         f.setException(x);
                     }
                 }

src/main/java/org/jenkinsci/plugins/workflow/cps/CpsThreadGroup.java

@@ -68,6 +68,7 @@
 import static org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.*;
 import static org.jenkinsci.plugins.workflow.cps.persistence.PersistenceContext.*;
 import org.jenkinsci.plugins.workflow.pickles.PickleFactory;
+import org.jenkinsci.plugins.workflow.support.storage.FlowNodeStorage;
 
 /**
  * List of {@link CpsThread}s that form a single {@link CpsFlowExecution}.
@@ -425,6 +426,16 @@ public CpsThreadDump getThreadDump() {
     void saveProgramIfPossible(boolean enteringQuietState) {
         if (this.getExecution() != null && (this.getExecution().getDurabilityHint().isPersistWithEveryStep()
                 || enteringQuietState)) {
+
+            try {  // Program may depend on flownodes being saved, so save nodes
+                FlowNodeStorage storage = this.execution.getStorage();
+                if (storage != null) {
+                    storage.flush();
+                }
+            } catch (IOException ioe) {
+                LOGGER.log(Level.WARNING, "Error persisting FlowNode storage before saving program", ioe);
+            }
+
             try {
                 saveProgram();
             } catch (IOException x) {