Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[JENKINS-55287] Improve error messages for nonresumable Pipelines #363

Closed
wants to merge 10 commits into from
Closed

[JENKINS-55287] Improve error messages for nonresumable Pipelines #363

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
ebb5d76
[JENKINS-55287] Improve error messages for nonresumable Pipelines
dwnusbaum Jun 18, 2020
b360ae0
Jenkins.isTerminating() cannot be used from terminators
dwnusbaum Jun 19, 2020
f631a44
Merge branch 'JENKINS-55287-logging' into JENKINS-55287
dwnusbaum Jun 19, 2020
686a6e4
Clarify log messages in CpsFlowExecution.checkpoint when the build is…
dwnusbaum Jun 19, 2020
eb08b5b
Don't set persistedClean to true in CpsFlowExecution.saveOwner at all
dwnusbaum Jun 19, 2020
2214c42
Always modify persistedClean in CpsFlowExecution.checkpoint, null it …
dwnusbaum Jun 19, 2020
b3a6847
Ignore RestartingLoadStepTest.updatedBindingsOnRestart because it is …
dwnusbaum Jun 29, 2020
2ad7e70
wip
dwnusbaum Jul 2, 2020
d0c638c
Merge branch 'master' into JENKINS-55287
dwnusbaum Aug 11, 2020
22e7086
Unignore RestartingLoadStepTest.updatedBindingsOnRestart
dwnusbaum Aug 11, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
62 changes: 44 additions & 18 deletions src/main/java/org/jenkinsci/plugins/workflow/cps/CpsFlowExecution.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -712,17 +712,26 @@ public void onLoad(FlowExecutionOwner owner) throws IOException {
this.owner = owner;

try {
initializeStorage(); // Throws exception and bombs out if we can't load FlowNodes
} catch (Exception ex) {
try {
initializeStorage(); // Throws exception and bombs out if we can't load FlowNodes
} catch (Exception ex) {
LOGGER.log(Level.WARNING, "Error initializing storage and loading nodes, will try to create placeholders for: "+this, ex);
if (!canResume()) {
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Alternatively, we could check this even before we attempt to initialize storage and just bail out right away. I don't know if that is too pessimistic, maybe there is a case where the Pipeline is not resumable but flow nodes are all up to date and so the optimistic behavior here is useful because you will still be able to see the existing flow graph in those cases?

// This case is expected for PERFORMANCE_OPTIMIZED Pipelines after a Jenkins crash (JENKINS-55287). The specific issue is
// usually that only the FlowStartNode has been persisted and so we cannot find the current head node in storage.
String message = "Unable to resume " + owner.getExecutable() + " because it was not saved before Jenkins shut down. Did Jenkins crash?";
LOGGER.log(Level.WARNING, message, ex);
ex = new AbortException(message); // Change the exception displayed in the build log to one that is more useful for users.
} else {
LOGGER.log(Level.WARNING, "Unable to resume " + owner.getExecutable() + " because its flow nodes could not be loaded", ex);
}
createPlaceholderNodes(ex);
return;
} catch (Exception ex2) {
Copy link
Member Author

@dwnusbaum dwnusbaum Jun 18, 2020 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is all mostly refactoring. The old code had this structure:

try {
  try {
    // code that can throw
  } catch (first) {
    // code that can throw
    return
  }
} catch (second) {
   throw second // first exception, if any, is totally lost
}

Now it has this structure:

try {
  // code that can throw
} catch (first) {
  try {
    // code that can throw
  } catch (second) {
    second.addSuppressed(first)
    throw second
  }
  return
}

ex2.addSuppressed(ex);
done = true;
programPromise = Futures.immediateFailedFuture(ex2);
throw new IOException("Failed to even create placeholder nodes for execution", ex2);
}
} catch (Exception ex) {
done = true;
programPromise = Futures.immediateFailedFuture(ex);
throw new IOException("Failed to even create placeholder nodes for execution", ex);
return;
}

try {
Expand All @@ -737,12 +746,17 @@ public void onLoad(FlowExecutionOwner owner) throws IOException {
}
} else { // See if we can/should resume build
if (canResume()) {
// TODO: I think we need to null out persistedClean here and resave the execution so that future
// resumptions are not misled by the fact that persistedClean was true before this resumption.
// CpsThreadGroup.run nulls out persistedClean after every step but it does not save that value
// for PERFORMANCE_OPTIMIZED Pipelines.
dwnusbaum marked this conversation as resolved.
Show resolved Hide resolved
loadProgramAsync(getProgramDataFile());
} else {
// TODO if possible, consider trying to close out unterminated blocks to keep existing graph history
// That way we can visualize the graph in some error cases.
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.");
String message = "Unable to resume " + owner.getExecutable() + " because it was not saved before Jenkins shut down. Did Jenkins crash?";
LOGGER.log(Level.WARNING, message);
throw new IOException(message);
}
}
} catch (Exception e) { // Broad catch ensures that failure to load do NOT nuke the master
Expand Down Expand Up @@ -1526,10 +1540,6 @@ public boolean isPaused() {
return false;
}

private void setPersistedClean(boolean persistedClean) { // Workaround for some issues with anonymous classes.
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unused

this.persistedClean = persistedClean;
}

/**
* Pause or unpause the execution.
*
Expand Down Expand Up @@ -1951,24 +1961,35 @@ void saveExecutionIfDurable() {
* Key note: to avoid deadlocks we need to ensure that we don't hold a lock on this CpsFlowExecution when running saveOwner
* or pre-emptively lock the run before locking the execution and saving. */
void saveOwner() {
/**
* We only want to update persistedClean if the program is over (in which case it doesn't matter), or if Jenkins
* is about to shut down (in which case it controls whether PERFORMANCE_OPTIMIZED Pipelines can be resumed).
*/
boolean updatePersistedClean = done || Jenkins.get().isTerminating();
dwnusbaum marked this conversation as resolved.
Show resolved Hide resolved
try {
if (this.owner != null && this.owner.getExecutable() instanceof Saveable) { // Null-check covers some anomalous cases we've seen
Saveable saveable = (Saveable)(this.owner.getExecutable());
persistedClean = true;
if (updatePersistedClean) {
persistedClean = true;
}
if (storage != null && storage.delegate != null) {
// Defensively flush FlowNodes to storage
try {
storage.flush();
} catch (Exception ex) {
LOGGER.log(Level.WARNING, "Error persisting FlowNodes for execution "+owner, ex);
persistedClean = false;
if (updatePersistedClean) {
persistedClean = false;
}
}
}
saveable.save();
}
} catch (IOException ex) {
LOGGER.log(Level.WARNING, "Error persisting Run "+owner, ex);
persistedClean = false;
if (updatePersistedClean) {
persistedClean = false;
}
}
}

Expand Down Expand Up @@ -2031,7 +2052,12 @@ public void onFailure(Throwable t) {
persistOk=false;
LOGGER.log(Level.WARNING, "Error persisting FlowNode storage before shutdown", ioe);
}
persistedClean = persistOk;
if (Jenkins.get().isTerminating()) {
// Only modify persistedClean if Jenkins is shutting down.
// TODO: We could set persistedClean to true when the build is just being paused, but then we would need
// to null it out and save again when the build was unpaused.
dwnusbaum marked this conversation as resolved.
Show resolved Hide resolved
persistedClean = persistOk;
}
try {
saveOwner();
} catch (Exception ex) {
Expand Down
7 changes: 3 additions & 4 deletions src/test/java/org/jenkinsci/plugins/workflow/cps/PersistenceProblemsTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,6 @@
import org.jenkinsci.plugins.workflow.support.steps.input.InputStepExecution;
import org.junit.Assert;
import org.junit.ClassRule;
import org.junit.Ignore;
import org.junit.Rule;
import org.junit.Test;
import org.jvnet.hudson.test.BuildWatcher;
Expand Down Expand Up @@ -244,7 +243,6 @@ public void inProgressNormal() throws Exception {
}

@Test
@Ignore
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These tests have been ignored since they were added. I am not sure why, but I went ahead and unignored them.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You probably already knew this, but I just noticed that these test cases seem to be duplicated in workflow-job-plugin's CpsPersistenceTest. Once the dust settles, it might be worth doing a sweep of the two copies to ensure that they are in sync with each other.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I think I will probably delete the copies in workflow-job after this. Ideally we would run the PCT in the CI builds here with just the core Pipeline plugins so that changes are tested against the newest versions of everything.

public void inProgressMaxPerfCleanShutdown() throws Exception {
final int[] build = new int[1];
story.then( j -> {
Expand All @@ -263,14 +261,14 @@ public void inProgressMaxPerfCleanShutdown() throws Exception {
});
}

@Issue("JENKINS-55287")
@Test
@Ignore
public void inProgressMaxPerfDirtyShutdown() throws Exception {
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the exact situation reported in JENKINS-55287 as far as I can tell.

final int[] build = new int[1];
final String[] finalNodeId = new String[1];
story.thenWithHardShutdown( j -> {
runBasicPauseOnInput(j, DEFAULT_JOBNAME, build, FlowDurabilityHint.PERFORMANCE_OPTIMIZED);
// SHOULD still save at end via persist-at-shutdown hooks
// Will not be saved since the persist-at-shutdown hooks will occur after the snapshot for thenWithHardShutdown is taken.
});
story.then( j->{
WorkflowJob r = j.jenkins.getItemByFullName(DEFAULT_JOBNAME, WorkflowJob.class);
Expand All @@ -279,6 +277,7 @@ public void inProgressMaxPerfDirtyShutdown() throws Exception {
j.waitForCompletion(run);
assertCompletedCleanly(run);
Assert.assertEquals(Result.FAILURE, run.getResult());
j.assertLogContains("was not saved before Jenkins shut down", run);
finalNodeId[0] = run.getExecution().getCurrentHeads().get(0).getId();
});
story.then(j-> {
Expand Down