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

svanoort · 2018-03-30T14:03:24Z

The main fixes are here jenkinsci/workflow-job-plugin#93 but this helps harden against the following and adds a bunch of diagnostic logging:

JENKINS-50199
JENKINS-46986
JENKINS-50407
Goodness knows which other JIRAs it fixes (probably ones marked as could-not-reproduce)

It also subsumes: #215

…smatches in the final FlowNode

…ersistence

…kins-49686

abayer

Not explicitly approving since this is still WIP and I don't want to confuse things for myself later, but looks good so far.

abayer · 2018-03-30T14:51:22Z

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

     * and for those we don't want to load the program state, so that check should be efficient.
     */
-    private boolean done;
+     Boolean done; // Only non-private for unit test use.


Extraneous leading space after indent? =)

abayer · 2018-03-30T14:52:52Z

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

        return iota.get();
    }

+    /** For diagnostic purposes only. */


So I personally appreciate it when diagnostics methods like this have javadoc or comments giving a quick explanation of what their diagnostics are meant to show - not a blocker by any means, just a casual request.

abayer · 2018-03-30T14:53:22Z

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

+
+            if (this.heads != null && this.heads.size() > 0) {
+                if (LOGGER.isLoggable(Level.INFO)) {
+                    LOGGER.log(Level.INFO, "Resetting heads to rebuild the Pipeline structure, tossing existing heads: "+getHeadsAsString());


oooo, this is a nice addition.

here would reduce to just

if (heads != null && !heads.isEmpty()) { LOGGER.log(Level.INFO, "Resetting heads to rebuild the Pipeline structure, tossing existing heads: {0}", heads); heads.clear(); }

abayer · 2018-03-30T14:54:57Z

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

    }

    @Override
+    @SuppressFBWarnings(value = "RC_REF_COMPARISON_BAD_PRACTICE_BOOLEAN", justification = "We want to explicitly check for boolean not-null and true")


Is it wrong that I love that with Boolean, you effectively can treat it as a, I dunno, troolean? What'd be the term for a boolean but for three possible states... =)

A trilean, acc. to Wikipedia.

abayer · 2018-03-30T14:56:11Z

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

    /** Report a fatal error in the VM. */
    void croak(Throwable t) {
        setResult(Result.FAILURE);
+        done = true;


Why Boolean.TRUE above but true here? Might be handy to mention why you're using one vs the other in one case (probably the Boolean.TRUE case, since that's not something you see as often).

abayer · 2018-03-30T14:58:54Z

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

                    writeChild(w, context, "start", st.getId(), String.class);
                }
+                if (e.done != null) {
+                    writeChild(w, context, "done", e.done, Boolean.class);


glee I can't remember off the top of my head why I care about having done persisted, but I know I do.

So long as it is making some test pass, fine with me…

abayer · 2018-03-30T15:00:26Z

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


-    void setNewHead(FlowNode v) {
+    void setNewHead(@Nonnull FlowNode v) {
+        if (v == null) {


So my brain briefly melts at the combination of @Nonnull and if (v == null) - I'm assuming this is defense-in-depth, with the @Nonnull covering compile-time scenarios and the if (v == null) covering even edgier-case scenarios?

Yeah, it's protecting against some things that shouldn't happen but yet were still happening in the wild, even though Findbugs didn't find issues at compile-time (probably it wasn't digging deeply enough).

Yeah, I have no problem with that approach - probably worth adding a comment explaining that, though. It'd be awfully easy for a later maintainer (i.e., me, because I'm forgetful) to not know/remember that and just think "Oh, that's a pointless null check, lemme clear the dead code".

Uh, this is package-private so we can trivially enumerate all the call sites and put in assertions there that the value is non-null unless that is trivially seen from code inspection, right?

abayer · 2018-03-30T15:01:22Z

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

        } catch (IOException e) {
            LOGGER.log(Level.FINE, "Failed to record new head: " + v, e);
        }
+        v.addAction(new TimingAction());


So the idea here is that we want to still do the TimingAction, notifyNewHead, etc, even if we can't store the node?

jglick · 2018-04-03T22:12:29Z

pom.xml

            <groupId>org.jenkins-ci.plugins.workflow</groupId>
            <artifactId>workflow-job</artifactId>
-            <version>2.17</version>
+            <version>2.18-20180329.215807-4</version>


polite to link to the upstream in a comment so we do not lose track

jglick · 2018-04-03T22:13:01Z

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

     * and for those we don't want to load the program state, so that check should be efficient.
     */
-    private boolean done;
+    Boolean done; // Only non-private for unit test use.


Best to document what a null value means here.

jglick · 2018-04-03T22:14:08Z

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

+        } else if (myHeads.size() == 0) {
+            return "empty-heads";
+        } else {
+            return myHeads.entrySet().stream().map(h->h.getKey()+"::"+h.getValue()).collect(Collectors.joining(","));


myHeads.toString not good enough??

jglick · 2018-04-03T22:15:27Z

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

+
+            if (this.heads != null && this.heads.size() > 0) {
+                if (LOGGER.isLoggable(Level.INFO)) {
+                    LOGGER.log(Level.INFO, "Resetting heads to rebuild the Pipeline structure, tossing existing heads: "+getHeadsAsString());


here would reduce to just

if (heads != null && !heads.isEmpty()) { LOGGER.log(Level.INFO, "Resetting heads to rebuild the Pipeline structure, tossing existing heads: {0}", heads); heads.clear(); }

jglick · 2018-04-03T22:16:51Z

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

                        h.setForDeserialize(storage.getNode(entry.getValue()));
                        heads.put(h.getId(), h);
                    } else {
+                        LOGGER.log(Level.WARNING, "Tried to load head FlowNodes for execution "+this.owner+" but FlowNode was not found in storage for head id:FlowNodeId "+entry.getKey()+":"+entry.getValue());


or just:

LOGGER.log(Level.WARNING, "Tried to load head FlowNodes for execution {0} but FlowNode was not found in storage for head id:FlowNodeId {1}", new Object[] {owner, entry});

jglick · 2018-04-03T22:19:48Z

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

                    writeChild(w, context, "start", st.getId(), String.class);
                }
+                if (e.done != null) {
+                    writeChild(w, context, "done", e.done, Boolean.class);


So long as it is making some test pass, fine with me…

jglick · 2018-04-03T22:20:19Z

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

                            setField(result, "iota", new AtomicInteger(iota));
+                        } else if (nodeName.equals("done")) {
+                            Boolean isDone = readChild(reader, context, Boolean.class, result);
+                            setField(result, "done", isDone);


So you are doing something with historical builds which omit this field, right? Is there some @LocalData test which fails if you comment out that “something”?

Historical builds have this field. Also I've now dropped the use of Boolean (wasn't needed, can use primitive).

jglick · 2018-04-03T22:20:32Z

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

                } else {
                    stillRunnable |= t.isRunnable();
                }
-


jglick · 2018-04-03T22:21:38Z

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


-    void setNewHead(FlowNode v) {
+    void setNewHead(@Nonnull FlowNode v) {
+        if (v == null) {


Uh, this is package-private so we can trivially enumerate all the call sites and put in assertions there that the value is non-null unless that is trivially seen from code inspection, right?

jglick · 2018-04-03T22:22:29Z

src/test/java/org/jenkinsci/plugins/workflow/cps/FlowDurabilityTest.java

            Assert.assertFalse("Should always be able to retrieve script", StringUtils.isEmpty(cpsFlow.getScript()));
            Assert.assertNull("We should have no Groovy shell left or that's a memory leak", cpsFlow.getShell());
            Assert.assertNull("We should have no Groovy shell left or that's a memory leak", cpsFlow.getTrustedShell());
+            assert cpsFlow.done == Boolean.TRUE;


assertEquals preferred

…tests plus pull in latest WF-JOB fixes

…fore being saved

rsandell · 2018-04-06T15:20:47Z

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

+        try {
+            saveOwner();
+        } catch (Exception ex) {
+            LOGGER.log(Level.WARNING, "Failed to persist WorkflowRun after noting a serious failure for run:", owner);


Should probably log the actual exception as well.

jglick

I guess?

jglick · 2018-04-06T23:38:37Z

pom.xml

            <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>


please link to upstream PRs

jglick · 2018-04-06T23:38:49Z

pom.xml

        <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>


file a request to update the parent POM

@jglick jenkinsci/plugin-pom#101 - Done

jglick · 2018-04-06T23:39:30Z

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

+                }
            }
+        } catch (Exception ex) {
+            done = Boolean.TRUE;


jglick · 2018-04-06T23:40:31Z

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

            exec.runInCpsVmThread(new FutureCallback<CpsThreadGroup>() {
                @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


BTW how does durability interact with saveState? Important.

@jglick CpsStepContext#saveState() follows the same rules as overall Program durability - if your DurabilityHint has isPersistWithEveryStep() (i.e. MAX_SURVIVABILITY or SURVIVABLE_NONATOMIC) it saves normally.

Otherwise (for PERFORMANCE_OPTIMIZED) it doesn't -- your program is not providing guaranteed persistence in the face of catastrophic system failures.

Of course with a clean shutdown the pipeline will persist via the @Terminator as part of shutdown, so that's fine.

svanoort and others added 14 commits March 15, 2018 22:41

Enable persistence of the done field to provide protection against mi…

a7a926e

…smatches in the final FlowNode

Hardening and logging for abnormal cases with onLoad and incomplete p…

7b2ba86

…ersistence

Findbugs fixes

c028682

More logging and done flags

046e27a

Testcases to verify final build state

d33c90c

Diagnostic logging when setNewHead called with null head

1ad3eb4

Downgrade one warning log to info

cf829bb

Diagnostics fix

a017be9

[JENKINS-50407] Trying to diagnose an NPE.

5d08569

Mention issue number in exception for easy tracking.

4c545d6

Merge branch 'master' into diag-JENKINS-50407

1f47c90

Consume latest WF-job snapshot and amend logging

b34e1f1

Merge remote-tracking branch 'jglick/diag-JENKINS-50407' into fix-jen…

ab88c6d

…kins-49686

More errorproofing in FlowHead

f4aad61

svanoort added the work-in-progress label Mar 30, 2018

abayer requested review from abayer and jglick March 30, 2018 14:50

abayer reviewed Mar 30, 2018

View reviewed changes

Apply the noted review changes

16dcb35

svanoort removed the work-in-progress label Apr 3, 2018

jglick changed the title ~~[WIP] Fix a whole wad of Resume issues and add a bunch of diagnostic logging for FlowHead problems etc~~ Fix a whole wad of Resume issues and add a bunch of diagnostic logging for FlowHead problems etc Apr 3, 2018

jglick approved these changes Apr 3, 2018

View reviewed changes

svanoort added 8 commits April 3, 2018 19:32

Bump wf-job version to version with more hardening

1a279ef

More robustness enhancements from fuzzing and extend/enhance fuzzing …

5aa15b5

…tests plus pull in latest WF-JOB fixes

Fix durability mode setting in test

b91d775

Additional robustness improvements, plus a bit more test coverage

e69a24c

Ensure that Program state always has its FlowNodes fully persisted be…

9d8f0b1

…fore being saved

Add additional testcase Javadocs

95d7ee2

Missing ignore for fuzzer test

a9c52d6

Update test harness dep to latest snapshot

a4110d2

svanoort requested a review from jglick April 6, 2018 13:20

Reduce one fuzz test timing so it cannot time out

773855b

abayer approved these changes Apr 6, 2018

View reviewed changes

rsandell reviewed Apr 6, 2018

View reviewed changes

Fix one error logging that missed the exception

91212d2

rsandell approved these changes Apr 6, 2018

View reviewed changes

svanoort mentioned this pull request Apr 6, 2018

"Dirty" restart enhancements jenkinsci/jenkins-test-harness#101

Merged

Update to test harness

5ecfd2c

jglick approved these changes Apr 6, 2018

View reviewed changes

svanoort mentioned this pull request Apr 8, 2018

Fix resume issues [JENKINS-49686] and [JENKINS-50199] and [JENKINS-50407] jenkinsci/workflow-job-plugin#93

Merged

Consume final workflow-job released version

1360644

svanoort merged commit 9b0848c into jenkinsci:master Apr 8, 2018

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

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

Uh oh!

Conversation

svanoort commented Mar 30, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

abayer left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

svanoort Apr 5, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jglick left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

svanoort commented Mar 30, 2018 •

edited

Loading

svanoort Apr 5, 2018 •

edited

Loading