[JENKINS-67164] Call StepExecution.onResume directly from WorkflowRun.onLoad rather than via FlowExecutionList.ItemListenerImpl to ensure step resumption #178

dwnusbaum · 2021-11-04T22:14:23Z

We have seen various reports of cases where a Pipeline resumes after a Jenkins restart and is occupying an executor slot, but the Pipeline in question appears to have already completed based on log output and it hangs forever after resuming. For example, see JENKINS-50199 (fixed via hardening a different resumption code path) and JENKINS-43587 (which maybe should not have been marked as resolved).

I was able to reproduce this issue when restoring Jenkins from a backup taken while Pipeline builds were in progress. The Pipelines in question were in the process of running a SynchronousNonBlockingStepExecution when the backup was taken, and that step should have failed when the Pipeline resumed and FlowExecutionListener$ItemListenerImpl called StepExecution.onResume, but this call never happened because the builds in question were not present in org.jenkinsci.plugins.workflow.flow.FlowExecutionList.xml on disk for some reason, so the execution just hung forever waiting for that step to complete. Additionally, the build logs indicated that the builds had already proceeded past this step, so it is not clear to me why program.dat was outdated. The Pipelines were using the standard PERFORMANCE_OPTIMIZED durability mode, and their build.xml files showed them as still in progress.

This PR attempts to harden the StepExecution resumption code by replacing FlowExecutionListener.ItemListenerImpl with a FlowExecutionListener that implements onResumed. WorkflowRun.onLoad directly calls FlowExecutionListener.fireOnResumed when it resumes in-progress Pipelines (happens automatically when WorkflowRun.onLoad is called), so it is guaranteed to be called for every Pipeline that resumes regardless of the stated of FlowExecutionList.

I will keep investigating to try to understand how this might happen in cases besides backups, since I think that this issue has been seen even when just restarting a controller normally.

Make sure you are opening from a topic/feature/bugfix branch (right side) and not your main branch!
Ensure that the pull request title represents the desired changelog entry
Please describe what you did
Link to relevant issues in GitHub or Jira
Link to relevant pull requests, esp. upstream and downstream changes
Ensure you have provided tests - that demonstrates feature works or fixes the issue

…han via FlowExecutionList to ensure resumption

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java

src/test/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionListTest.java

dwnusbaum · 2021-11-04T22:21:43Z

src/test/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionListTest.java

+            // TODO: Unclear how this might happen in practice.
+            FlowExecutionList.get().unregister(b.asFlowExecutionOwner());


As mentioned, I am not sure how this might happen outside of something like a backup where files are being copied indiscriminately. The code around build completion in WorkflowRun looks reasonable to me from a quick glance, and the call to unregister is the final thing that happens, so the only thing that comes to mind is that there is some issue causing the build to not be saved as expected, for example perhaps some issue with a BulkChange being aborted or something like that.

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java

…not already present

jglick

Looking right.

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java

jglick · 2021-11-05T19:37:05Z

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java

+                public void onSuccess(List<StepExecution> result) {
+                    FlowExecutionList list = FlowExecutionList.get();
+                    FlowExecutionOwner owner = e.getOwner();
+                    if (!list.runningTasks.contains(owner)) {


Maybe check isComplete first?

Yeah I was thinking about that as well. CpsFlowExecution.isComplete is checked in CpsFlowExecution.onLoad before loadProgramAsync gets called, but WorkflowRun.onLoad only checks CpsFlowExecution.isComplete() if WorkflowRun.completed is null, which I think should only be true for old Pipelines from before WorkflowRun.completed was added (which seems wrong, probably better to always check in case there is a mismatch between the serialized state of the execution and the run, so I will look at that in a bit), so there is no guarantee about the value of CpsFlowExecution.isComplete here as far as I can tell, so it might be worth checking.

I also wasn't sure if it would be possible for there to be a timing issue, for example if the pipeline was suspended somewhere where it doesn't need any additional input to proceed and so the CPS VM thread finishes the build while we are on another thread still in WorkflowRun.onLoad.

if it would be possible for there to be a timing issue

Almost certainly.

Almost certainly.

If this is the case though, then we cannot fix the issue here, because there is no synchronization that can guarantee that the execution does not complete right after we check isComplete but before we do anything else. Maybe the CPS VM thread should not attempt to execute anything until WorkflowRun.onLoad finishes or something like that.

What makes you think the observed problem is the result of a race condition?

I'm not following your question. I just mean that it is not clear to me whether checking isComplete here actually gives us any useful guarantees, partly because WorkflowRun.onLoad is not guaranteed to check it and partly because the execution actually completing will happen on the CPS VM thread, which is unrelated to the thread calling WorkflowRun.onLoad. I don't necessarily think that the underlying reported problem is a race condition.

When I said

then we cannot fix the issue here,

I just meant that we cannot fix any timing issues related to checking isComplete or not. Maybe that was not clear.

Ah ok, so reading through WorkflowRun.onLoad again, it is guaranteed to call isComplete inside of WorkflowRun.getExecution here, and if the execution is complete, it marks the WorkflowRun as complete (this was the fix for the symptoms of JENKINS-50199), so this condition would be false and so FlowExecutionListener.fireResumed would be skipped along with ResumeStepExecutionListener.onResumed if the execution was marked as complete in its serialized form.

That leaves us with a potential case where WorkflowRun.getExecution loads and resumes the execution, which has not yet completed, but then the execution completes before ResumeStepExecutionListener.onResumed has been called by WorkflowRun.onLoad after WorkflowRun.getExecution and so we resume the steps unnecessarily. We could check isComplete here in case this happens, but it seems somewhat unlikely, and the issue is even if we do check it, the execution could complete right after the check before ResumeStepExecutionListener.onResumed attempts to resume the step executions, so we wouldn't really be guaranteed to prevent the problem. We could try to modify execution resumption to somehow only start after WorkflowRun.onLoad returns, but that seems like a somewhat risky change unless we have some evidence that it is a problem in practice.

I think I'll go ahead and add the isComplete check since it won't hurt and could potentially help in some case, but I'll also add a comment mentioning that execution is asynchronous and so there could still be problems.

Check added with a comment in e9f2421.

…ng anything

dwnusbaum · 2021-11-12T22:10:29Z

Once the build completes I will do some downstream testing, probably just with a draft PR against https://github.com/jenkinsci/bom.

jglick

I believe this should be safe.

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java

src/test/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionListTest.java

…epExecutions

dwnusbaum · 2021-12-15T15:00:13Z

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java

+                    }
+                }
+
+            }, MoreExecutors.directExecutor()); // TODO: Unclear if we need to run this asynchronously or if StepExecution.onResume has any particular thread requirements.


It looks like running this synchronously caused JENKINS-67351. I will look into switching to using a different thread.

…kflowRun.onLoad rather than via FlowExecutionList.ItemListenerImpl to ensure step resumption (jenkinsci#178)" This reverts commit 37c8c49.

Call StepExecution.onResume directly from WorkflowRun.onLoad rather t…

c4b18fe

…han via FlowExecutionList to ensure resumption

dwnusbaum commented Nov 4, 2021

View reviewed changes

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java Show resolved Hide resolved

jglick requested changes Nov 4, 2021

View reviewed changes

src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionList.java Outdated Show resolved Hide resolved

dwnusbaum added 2 commits November 5, 2021 14:28

Add FlowExecutionList$ItemListenerImpl back in

bdcda5e

Register Pipelines in FlowExecutionList when they resume if they are …

b3ad2d4

…not already present

jglick approved these changes Nov 5, 2021

View reviewed changes

dwnusbaum added 2 commits November 5, 2021 16:09

Remove unnecessary use of Guice so import can be dropped

ec57f3d

Check FlowExecution.isComplete ResumeStepExecutionListener before doi…

e9f2421

…ng anything

jglick approved these changes Nov 15, 2021

View reviewed changes

dwnusbaum mentioned this pull request Nov 15, 2021

[Not for merge] Test workflow-api StepExecution resumption changes jenkinsci/bom#723

Closed

dwnusbaum added 2 commits November 15, 2021 12:43

Use SpotBugs nullability annotations

e56d14e

[JENKINS-67164] Add issue reference to FlowExecutionListTest.resumeSt…

d403297

…epExecutions

dwnusbaum added the bug label Nov 17, 2021

dwnusbaum marked this pull request as ready for review November 17, 2021 21:29

dwnusbaum requested a review from car-roll November 17, 2021 21:29

car-roll approved these changes Nov 19, 2021

View reviewed changes

car-roll merged commit 37c8c49 into jenkinsci:master Nov 19, 2021

jglick mentioned this pull request Dec 14, 2021

[JENKINS-40161] Handle exceptions from StepExecution.onResume #187

Merged

dwnusbaum commented Dec 15, 2021

View reviewed changes

dwnusbaum mentioned this pull request Dec 15, 2021

[JENKINS-67351] Avoid deadlock when resuming Pipelines in some cases #188

Merged

6 tasks

dwnusbaum mentioned this pull request Jan 14, 2022

Revert fixes related to JENKINS-67351 and JENKINS-67164 #198

Merged

6 tasks

dwnusbaum deleted the step-resumption-reliability branch May 10, 2022 15:43

jglick mentioned this pull request May 11, 2022

[JENKINS-67164] Call StepExecution.onResume in response to WorkflowRun.onLoad not FlowExecutionList.ItemListenerImpl #221

Merged

dwnusbaum mentioned this pull request Jan 14, 2025

Resume Pipeline builds asynchronously #368

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[JENKINS-67164] Call StepExecution.onResume directly from WorkflowRun.onLoad rather than via FlowExecutionList.ItemListenerImpl to ensure step resumption #178

[JENKINS-67164] Call StepExecution.onResume directly from WorkflowRun.onLoad rather than via FlowExecutionList.ItemListenerImpl to ensure step resumption #178

dwnusbaum commented Nov 4, 2021 •

edited

Loading

dwnusbaum Nov 4, 2021

jglick left a comment

jglick Nov 5, 2021

dwnusbaum Nov 5, 2021 •

edited

Loading

jglick Nov 5, 2021

dwnusbaum Nov 5, 2021 •

edited

Loading

jglick Nov 5, 2021

dwnusbaum Nov 5, 2021

dwnusbaum Nov 5, 2021

dwnusbaum Nov 12, 2021

dwnusbaum Nov 12, 2021

dwnusbaum commented Nov 12, 2021

jglick left a comment

dwnusbaum Dec 15, 2021

		// TODO: Unclear how this might happen in practice.
		FlowExecutionList.get().unregister(b.asFlowExecutionOwner());

[JENKINS-67164] Call StepExecution.onResume directly from WorkflowRun.onLoad rather than via FlowExecutionList.ItemListenerImpl to ensure step resumption #178

[JENKINS-67164] Call StepExecution.onResume directly from WorkflowRun.onLoad rather than via FlowExecutionList.ItemListenerImpl to ensure step resumption #178

Conversation

dwnusbaum commented Nov 4, 2021 • edited Loading

Choose a reason for hiding this comment

jglick left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dwnusbaum Nov 5, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dwnusbaum Nov 5, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dwnusbaum commented Nov 12, 2021

jglick left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dwnusbaum commented Nov 4, 2021 •

edited

Loading

dwnusbaum Nov 5, 2021 •

edited

Loading

dwnusbaum Nov 5, 2021 •

edited

Loading