Skip to content

ContinuedTask cannot rely on queue scheduling order #472

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

Closed
jglick wants to merge 2 commits into from

Demonstrating race condition with `ContinuedTask`

22de9fc
Select commit
Loading
Failed to load commit list.
Closed

ContinuedTask cannot rely on queue scheduling order #472

Demonstrating race condition with `ContinuedTask`
22de9fc
Select commit
Loading
Failed to load commit list.
ci.jenkins.io / Tests / linux-21 / Build (linux-21) failed Aug 18, 2025 in 0s

org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest.tardyResume failed

org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest.tardyResume failed

Details

org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest.tardyResume

unexpected build status; build log was:
------
Started
[Pipeline] Start of Pipeline
[Pipeline] slowToResume
[Pipeline] {
[Pipeline] node
Running on remote in /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/agent-work-dirs/remote/workspace/tardy
[Pipeline] {
[Pipeline] semaphore
Resuming build at Mon Aug 18 23:46:49 GMT 2025 after Jenkins restart
Will resume outer step…
…resumed.
Waiting for reconnection of remote before proceeding with build
remote has been removed for 15 sec; assuming it is not coming back, and terminating node step
Ready to run at Mon Aug 18 23:47:07 GMT 2025
[Pipeline] }
[Pipeline] // node
[Pipeline] }
[Pipeline] // slowToResume
[Pipeline] End of Pipeline
Timeout waiting for agent to come back
org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 6efd156d-2cf0-4b9f-a703-8bc360b77d66
Finished: ABORTED

------

Expected: is <SUCCESS>
     but: was <ABORTED>
Stack trace 
java.lang.AssertionError: 
unexpected build status; build log was:
------
Started
[Pipeline] Start of Pipeline
[Pipeline] slowToResume
[Pipeline] {
[Pipeline] node
Running on remote in /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/agent-work-dirs/remote/workspace/tardy
[Pipeline] {
[Pipeline] semaphore
Resuming build at Mon Aug 18 23:46:49 GMT 2025 after Jenkins restart
Will resume outer step…
…resumed.
Waiting for reconnection of remote before proceeding with build
remote has been removed for 15 sec; assuming it is not coming back, and terminating node step
Ready to run at Mon Aug 18 23:47:07 GMT 2025
[Pipeline] }
[Pipeline] // node
[Pipeline] }
[Pipeline] // slowToResume
[Pipeline] End of Pipeline
Timeout waiting for agent to come back
org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 6efd156d-2cf0-4b9f-a703-8bc360b77d66
Finished: ABORTED

------

Expected: is <SUCCESS>
     but: was <ABORTED>
	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
	at org.jvnet.hudson.test.JenkinsRule.assertBuildStatus(JenkinsRule.java:1462)
	at org.jvnet.hudson.test.JenkinsRule.assertBuildStatusSuccess(JenkinsRule.java:1490)
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest.lambda$tardyResume$13(ExecutorStepDynamicContextTest.java:284)
	at org.jvnet.hudson.test.JenkinsSessionRule$2.evaluate(JenkinsSessionRule.java:107)
	at org.jvnet.hudson.test.JenkinsRule$1.evaluate(JenkinsRule.java:658)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.lang.Thread.run(Thread.java:1583)
Standard error 
0.130 [id=610]	INFO	o.jvnet.hudson.test.JenkinsRule#createWebServer2: Running on http://localhost:42999/jenkins/
   0.200 [id=623]	INFO	jenkins.InitReactorRunner$1#onAttained: Started initialization
   0.201 [id=622]	INFO	jenkins.InitReactorRunner$1#onAttained: Listed all plugins
   0.203 [id=626]	INFO	j.b.api.BouncyCastlePlugin#start: /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/plugins/bouncycastle-api/WEB-INF/optional-lib not found; for non RealJenkinsRule this is fine and can be ignored.
   0.407 [id=624]	INFO	jenkins.InitReactorRunner$1#onAttained: Prepared all plugins
   0.408 [id=627]	INFO	jenkins.InitReactorRunner$1#onAttained: Started all plugins
   0.409 [id=622]	INFO	jenkins.InitReactorRunner$1#onAttained: Augmented all extensions
   0.879 [id=629]	INFO	jenkins.InitReactorRunner$1#onAttained: System config loaded
   0.879 [id=629]	INFO	jenkins.InitReactorRunner$1#onAttained: System config adapted
   0.879 [id=623]	INFO	jenkins.InitReactorRunner$1#onAttained: Loaded all jobs
   0.880 [id=628]	INFO	jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
   0.903 [id=628]	INFO	jenkins.InitReactorRunner$1#onAttained: Completed initialization
   0.942 [id=610]	INFO	o.j.p.w.t.s.SemaphoreStep$State#get: Initializing state in /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990
   0.946 [id=651]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#saveLater: scheduling save of [tardy#1]
   0.947 [id=636]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#save: saving [tardy#1] to /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/org.jenkinsci.plugins.workflow.flow.FlowExecutionList.xml
   0.988 [tardy #1] Started
   0.988 [tardy #1] [Pipeline] Start of Pipeline
   1.014 [id=94]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask#<init>: scheduling ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1}
   1.015 [id=652]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1}
   1.015 [id=652]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1}
   1.039 [tardy #1] [Pipeline] slowToResume
   1.039 [tardy #1] [Pipeline] {
   1.039 [tardy #1] [Pipeline] node
   1.888 [id=337]	INFO	o.j.h.test.SimpleCommandLauncher#launch: agent launched for remote
   1.888 [id=656]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1}
   1.888 [id=656]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[5:node]:tardy#1}
   1.948 [id=646]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask$PlaceholderExecutable#lambda$run$4: waiting on CpsStepContext[5:node]:tardy#1
   1.949 [id=94]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask$PlaceholderExecutable#lambda$run$1: started CpsStepContext[5:node]:tardy#1
   1.969 [id=95]	INFO	o.j.p.w.t.s.SemaphoreStep$Execution#start: Blocking tardy/1
   1.974 [id=658]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#saveLater: scheduling save of [tardy#1, prompt#1]
   1.975 [id=621]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#save: saving [tardy#1, prompt#1] to /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/org.jenkinsci.plugins.workflow.flow.FlowExecutionList.xml
   1.995 [tardy #1] Running on remote in /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/agent-work-dirs/remote/workspace/tardy
   1.995 [tardy #1] [Pipeline] {
   1.995 [tardy #1] [Pipeline] semaphore
   1.995 [prompt #1] Started
   2.009 [id=95]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask#<init>: scheduling ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   2.046 [prompt #1] [Pipeline] Start of Pipeline
   2.046 [prompt #1] [Pipeline] node
   7.027 [prompt #1] Still waiting to schedule task
   7.027 [prompt #1] Waiting for next available executor on ‘remote’
   7.092 [id=610]	WARNING	o.j.h.t.RemainingActivityListener#onTearDown: tardy #1 still seems to be running, which could break deletion of log files or metadata
   7.092 [id=339]	INFO	hudson.remoting.Request$2#run: Failed to send back a reply to the request RPCRequest:hudson.remoting.RemoteClassLoader$IClassLoader.fetch3[java.lang.String](2): hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@30c251e9:remote": channel is already closed
   7.095 [id=610]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
   7.097 [id=610]	FINE	o.j.p.w.flow.FlowExecutionList#saveAll: ensuring all executions are saved
   7.141 [id=654]	INFO	o.j.h.test.SimpleCommandLauncher#afterDisconnect: killed Process[pid=9864, exitValue=0] with {HUDSON_COOKIE=a81d10af-7fc7-45b4-8888-4592c90a3b2b} for remote
   7.141 [id=86]	INFO	o.j.h.test.SimpleCommandLauncher#afterDisconnect: no process for remote
   7.141 [id=610]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
   0.132 [id=669]	INFO	o.jvnet.hudson.test.JenkinsRule#createWebServer2: Running on http://localhost:42999/jenkins/
   0.197 [id=681]	INFO	jenkins.InitReactorRunner$1#onAttained: Started initialization
   0.198 [id=681]	INFO	jenkins.InitReactorRunner$1#onAttained: Listed all plugins
   0.201 [id=686]	INFO	j.b.api.BouncyCastlePlugin#start: /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/plugins/bouncycastle-api/WEB-INF/optional-lib not found; for non RealJenkinsRule this is fine and can be ignored.
   0.401 [id=682]	INFO	jenkins.InitReactorRunner$1#onAttained: Prepared all plugins
   0.403 [id=688]	INFO	jenkins.InitReactorRunner$1#onAttained: Started all plugins
   0.403 [id=681]	INFO	jenkins.InitReactorRunner$1#onAttained: Augmented all extensions
   0.555 [id=681]	INFO	jenkins.InitReactorRunner$1#onAttained: System config loaded
   0.555 [id=681]	INFO	jenkins.InitReactorRunner$1#onAttained: System config adapted
   0.558 [id=683]	INFO	jenkins.InitReactorRunner$1#onAttained: Loaded all jobs
   0.559 [id=683]	INFO	jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
   0.578 [id=685]	INFO	jenkins.InitReactorRunner$1#onAttained: Completed initialization
   0.584 [id=703]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#load: loaded: [tardy#1, prompt#1]
   0.596 [id=703]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:null]:prompt#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:null]:prompt#1}
   0.596 [id=703]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:null]:prompt#1}
   0.644 [id=95]	FINE	o.j.p.w.f.FlowExecutionList$ResumeStepExecutionListener$1#onSuccess: Will resume [org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@14e5f567]
   0.644 [id=705]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.644 [id=95]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Checking status with nodes={StepStartNode[id=3, exec=CpsFlowExecution[prompt#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@14e5f567} enclosing={} processing=[]
   0.644 [id=705]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: org.jenkinsci.plugins.workflow.job.AfterRestartTask@3a709b9f is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.644 [id=95]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Ready to resume: {StepStartNode[id=3, exec=CpsFlowExecution[prompt#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@14e5f567}
   0.644 [id=705]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.644 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: About to resume StepStartNode[id=3, exec=CpsFlowExecution[prompt#1]] ~ org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@14e5f567
   0.645 [id=705]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.645 [id=705]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: org.jenkinsci.plugins.workflow.job.AfterRestartTask@3a709b9f is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.645 [id=705]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.645 [id=339]	FINE	o.j.p.w.s.s.ExecutorStepExecution#onResume: node block CpsStepContext[3:node]:prompt#1 not yet scheduled, checking for an existing queue item
   0.646 [id=339]	FINE	o.j.p.w.s.s.ExecutorStepExecution#onResume: QueueItemAction with id=43 found for node block CpsStepContext[3:node]:prompt#1
   0.647 [id=339]	FINE	o.j.p.w.s.s.ExecutorStepExecution#onResume: Found Queue.Item hudson.model.Queue$BuildableItem:ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}:43 for node block CpsStepContext[3:node]:prompt#1; should be fine
   0.647 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: Finished resuming StepStartNode[id=3, exec=CpsFlowExecution[prompt#1]] ~ org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@14e5f567
   0.647 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Checking status with nodes={} enclosing={} processing=[]
   0.647 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Done
   0.649 [id=707]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.649 [id=707]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.654 [prompt #1] Resuming build at Mon Aug 18 23:46:49 GMT 2025 after Jenkins restart
   0.654 [prompt #1] Ready to run at Mon Aug 18 23:46:49 GMT 2025
   0.673 [id=692]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#resume: eagerly loaded CpsFlowExecution[tardy#1]
   0.673 [id=692]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#resume: eagerly loaded CpsFlowExecution[prompt#1]
   0.674 [id=708]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.674 [id=708]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: org.jenkinsci.plugins.workflow.job.AfterRestartTask@5a7c4923 is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.674 [id=708]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   0.678 [id=94]	FINE	o.j.p.w.f.FlowExecutionList$ResumeStepExecutionListener$1#onSuccess: Will resume [org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest$SlowToResumeStep$Execution@7d3e1c2c, org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@5c018831, org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae]
   0.683 [id=94]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Checking status with nodes={StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest$SlowToResumeStep$Execution@7d3e1c2c, StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@5c018831, StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae} enclosing={StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]], StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]} processing=[]
   0.683 [id=94]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Ready to resume: {StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest$SlowToResumeStep$Execution@7d3e1c2c}
   0.683 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: About to resume StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]] ~ org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest$SlowToResumeStep$Execution@7d3e1c2c
   0.704 [tardy #1] Resuming build at Mon Aug 18 23:46:49 GMT 2025 after Jenkins restart
   0.705 [tardy #1] Will resume outer step…
   1.527 [id=86]	INFO	o.j.h.test.SimpleCommandLauncher#launch: agent launched for remote
   1.527 [id=713]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1} is not continued, so it would not block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   1.527 [id=713]	FINER	o.j.p.d.e.ContinuedTask$Scheduler#canTake: no reason to block ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1}
   1.584 [id=697]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask$PlaceholderExecutable#lambda$run$4: waiting on CpsStepContext[3:node]:prompt#1
   1.584 [id=95]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask$PlaceholderExecutable#lambda$run$1: started CpsStepContext[3:node]:prompt#1
   1.605 [id=94]	INFO	o.j.p.w.t.s.SemaphoreStep$Execution#start: Blocking prompt/1
   1.612 [prompt #1] Running on remote in /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/agent-work-dirs/remote/workspace/prompt
   1.613 [prompt #1] [Pipeline] {
   1.613 [prompt #1] [Pipeline] semaphore
   3.684 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: Finished resuming StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]] ~ org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest$SlowToResumeStep$Execution@7d3e1c2c
   3.684 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Checking status with nodes={StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@5c018831, StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae} enclosing={StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]], StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]} processing=[]
   3.684 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Ready to resume: {StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@5c018831}
   3.684 [id=87]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: About to resume StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]] ~ org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@5c018831
   3.685 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepDynamicContext#resume: scheduled hudson.model.Queue$WaitingItem:ExecutorStepExecution.PlaceholderTask{label=remote,context=CpsStepContext[5:node]:tardy#1}:46 for /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/agent-work-dirs/remote/workspace/tardy on remote
   3.726 [tardy #1] …resumed.
   3.726 [tardy #1] Waiting for reconnection of remote before proceeding with build
  18.685 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepDynamicContext#resume: failed to wait for hudson.model.Queue$WaitingItem:ExecutorStepExecution.PlaceholderTask{label=remote,context=CpsStepContext[5:node]:tardy#1}:46; outstanding queue items: [hudson.model.Queue$BuildableItem:ExecutorStepExecution.PlaceholderTask{label=remote,context=CpsStepContext[5:node]:tardy#1}:46]; running executables: [Thread[#695,Executor #0 for Built-In Node,5,main], Thread[#696,Executor #1 for Built-In Node,5,main], Thread[#697,Executor #0 for remote : executing PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{label=contended,context=CpsStepContext[3:node]:prompt#1},5,]]
java.util.concurrent.TimeoutException
	at hudson.remoting.AsyncFutureImpl.get(AsyncFutureImpl.java:107)
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContext.resume(ExecutorStepDynamicContext.java:110)
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution.onResume(ExecutorStepExecution.java:240)
	at org.jenkinsci.plugins.workflow.flow.FlowExecutionList$ParallelResumer.lambda$run$6(FlowExecutionList.java:478)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
	at jenkins.util.ErrorLoggingExecutorService.lambda$wrap$0(ErrorLoggingExecutorService.java:51)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)
  18.686 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepExecution#stop: stopping one of [hudson.model.Queue$BuildableItem:ExecutorStepExecution.PlaceholderTask{label=remote,context=CpsStepContext[5:node]:tardy#1}:46]
org.jenkinsci.plugins.workflow.steps.FlowInterruptedException
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContext.resume(ExecutorStepDynamicContext.java:114)
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution.onResume(ExecutorStepExecution.java:240)
	at org.jenkinsci.plugins.workflow.flow.FlowExecutionList$ParallelResumer.lambda$run$6(FlowExecutionList.java:478)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
	at jenkins.util.ErrorLoggingExecutorService.lambda$wrap$0(ErrorLoggingExecutorService.java:51)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)
  18.686 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepExecution#stop: canceled hudson.model.Queue$BuildableItem:ExecutorStepExecution.PlaceholderTask{label=remote,context=CpsStepContext[5:node]:tardy#1}:46
  18.686 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepExecution#stop: no match on null
  18.686 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepExecution#stop: no match on null
  18.686 [id=87]	FINE	o.j.p.w.s.s.ExecutorStepExecution#stop: no match on PlaceholderExecutable:ExecutorStepExecution.PlaceholderTask{label=remote,context=CpsStepContext[3:node]:prompt#1} with CpsStepContext[3:node]:prompt#1 vs. CpsStepContext[5:node]:tardy#1
  18.686 [id=87]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: Finished resuming StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]] ~ org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution@5c018831
  18.686 [id=87]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Checking status with nodes={StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae} enclosing={StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]], StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]} processing=[]
  18.686 [id=87]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Ready to resume: {StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae}
  18.687 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: About to resume StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]] ~ org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae
  18.687 [id=94]	INFO	o.j.p.w.t.s.SemaphoreStep$Execution#stop: Stopping tardy/1
org.jenkinsci.plugins.workflow.steps.FlowInterruptedException
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContext.resume(ExecutorStepDynamicContext.java:114)
	at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution.onResume(ExecutorStepExecution.java:240)
	at org.jenkinsci.plugins.workflow.flow.FlowExecutionList$ParallelResumer.lambda$run$6(FlowExecutionList.java:478)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
	at jenkins.util.ErrorLoggingExecutorService.lambda$wrap$0(ErrorLoggingExecutorService.java:51)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
Caused: org.jenkinsci.plugins.workflow.steps.FlowInterruptedException
	at org.jenkinsci.plugins.workflow.cps.CpsStepContext$2.onSuccess(CpsStepContext.java:408)
	at org.jenkinsci.plugins.workflow.cps.CpsStepContext$2.onSuccess(CpsStepContext.java:388)
	at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$4$1.run(CpsFlowExecution.java:995)
	at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService.lambda$wrap$2(CpsVmExecutorService.java:85)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:139)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
	at jenkins.util.ErrorLoggingExecutorService.lambda$wrap$0(ErrorLoggingExecutorService.java:51)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$1.call(CpsVmExecutorService.java:53)
	at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$1.call(CpsVmExecutorService.java:50)
	at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:136)
	at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:275)
	at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService.lambda$categoryThreadFactory$0(CpsVmExecutorService.java:50)
	at java.base/java.lang.Thread.run(Thread.java:1583)
  18.688 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#lambda$run$6: Finished resuming StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]] ~ org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep$Execution@1f8c2cae
  18.689 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Checking status with nodes={} enclosing={StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=3, exec=CpsFlowExecution[tardy#1]], StepAtomNode[id=7, exec=CpsFlowExecution[tardy#1]]=StepStartNode[id=5, exec=CpsFlowExecution[tardy#1]]} processing=[]
  18.689 [id=339]	FINE	o.j.p.w.f.FlowExecutionList$ParallelResumer#run: Done
  18.707 [id=95]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask$Callback#finished: finished CpsStepContext[5:node]:tardy#1
  18.708 [id=95]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask#finish: no AsynchronousExecution associated with CpsStepContext[5:node]:tardy#1 (JENKINS-30759 maybe finished before asynch execution was even scheduled?)
  18.708 [id=95]	FINE	o.j.p.w.s.s.ExecutorStepExecution$PlaceholderTask$Callback#finished: was unable to cancel any leftover task from CpsStepContext[5:node]:tardy#1
  18.722 [tardy #1] remote has been removed for 15 sec; assuming it is not coming back, and terminating node step
  18.722 [tardy #1] Ready to run at Mon Aug 18 23:47:07 GMT 2025
  18.722 [tardy #1] [Pipeline] }
  18.722 [tardy #1] [Pipeline] // node
  18.772 [tardy #1] [Pipeline] }
  18.773 [tardy #1] [Pipeline] // slowToResume
  18.773 [tardy #1] [Pipeline] End of Pipeline
  18.776 [id=669]	INFO	o.j.p.w.test.steps.SemaphoreStep#success: Planning to unblock tardy/1 as success
  18.780 [tardy #1] Timeout waiting for agent to come back
  18.780 [tardy #1] org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 6efd156d-2cf0-4b9f-a703-8bc360b77d66
  18.780 [tardy #1] Finished: ABORTED
  18.780 [id=95]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#unregister: unregistered tardy#1
  18.780 [id=95]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#saveLater: scheduling save of [prompt#1]
  18.780 [id=691]	FINE	o.j.p.w.f.FlowExecutionList$DefaultStorage#save: saving [prompt#1] to /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990/org.jenkinsci.plugins.workflow.flow.FlowExecutionList.xml
  18.785 [id=669]	WARNING	o.j.h.t.RemainingActivityListener#onTearDown: prompt #1 still seems to be running, which could break deletion of log files or metadata
  18.788 [id=669]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
  18.790 [id=669]	FINE	o.j.p.w.flow.FlowExecutionList#saveAll: ensuring all executions are saved
  18.831 [id=711]	INFO	o.j.h.test.SimpleCommandLauncher#afterDisconnect: killed Process[pid=9953, exitValue=0] with {HUDSON_COOKIE=1848ed73-dbe0-4533-a40b-eaf87c02c39c} for remote
  18.832 [id=87]	INFO	o.j.h.test.SimpleCommandLauncher#afterDisconnect: no process for remote
  18.832 [id=669]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
  18.916 [id=1]	INFO	o.j.h.t.TemporaryDirectoryAllocator#dispose: deleting /home/jenkins/agent/workspace/_durable-task-step-plugin_PR-472/target/tmp/j h3967690491880588990
Standard out 
=== Starting tardyResume(org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest)
=== Starting tardyResume(org.jenkinsci.plugins.workflow.support.steps.ExecutorStepDynamicContextTest)
View more details on ci.jenkins.io