Skip to content

Hung build after FatalRejectedExecutionException from handleExit #455

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
Merged
jglick merged 4 commits into from
Jun 23, 2025
Merged

Hung build after FatalRejectedExecutionException from handleExit #455

jglick merged 4 commits into from
Jun 23, 2025

Conversation

@jglick
Copy link
Member

@jglick jglick commented Jun 23, 2025 •
edited
Loading

A race condition not caught in the new test in #323.

…
2025-06-23 18:40:13.231+0000 [id=75]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
2025-06-23 18:40:13.249+0000 [id=75]	INFO	o.j.p.w.s.d.e.FinishProcess#run: Touching …/f
[p#1]    1.610 + set +x
[p#1]    1.610 Pausing (Preparing for shutdown)
   1.886 [remote] [id=61]	FINE	o.j.p.d.BourneShellScript$ShellController#exitStatus: found exit code 0 in …/agent/workspace/p@tmp/durable-27c88019
   1.889 [remote] [id=61]	FINE	o.j.p.d.FileMonitoringTask$Watcher#run: org.jenkinsci.plugins.durabletask.FileMonitoringTask$Watcher@464cc035 exiting with code 0
   1.890 [remote] [id=61]	FINE	o.j.p.w.s.d.DurableTaskStep$Execution$NewlineSafeTaskListener$1#close: calling close with nl=true
2025-06-23 18:40:13.296+0000 [id=170]	FINE	o.j.p.w.s.d.DurableTaskStep$Execution#exited: asynchronous exit notification with code 0 in …/agent/workspace/p on remote
2025-06-23 18:40:13.298+0000 [id=170]	WARNING	o.j.p.w.cps.CpsStepContext$2#onFailure: Failed to proceed after CpsStepContext[5:sh]:p#1
org.jenkinsci.remoting.util.ExecutorServiceUtils$FatalRejectedExecutionException: Cannot execute the command java.util.concurrent.FutureTask@1206600b[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@7628b9c4[Wrapped task = org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$$Lambda/0x00007841e07d77f8@790270a2]]. The executor service is shutting down
	at hudson.remoting.SingleLaneExecutorService.execute(SingleLaneExecutorService.java:115)
	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123)
	at jenkins.util.InterceptingExecutorService.submit(InterceptingExecutorService.java:46)
	at PluginClassLoader for workflow-cps//org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$4.onSuccess(CpsFlowExecution.java:992)
	at PluginClassLoader for workflow-cps//org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$4.onSuccess(CpsFlowExecution.java:987)
	at PluginClassLoader for workflow-support//org.jenkinsci.plugins.workflow.support.concurrent.Futures$1.run(Futures.java:147)
	at PluginClassLoader for workflow-support//org.jenkinsci.plugins.workflow.support.concurrent.DirectExecutor.execute(DirectExecutor.java:33)
	at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1299)
	at com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:763)
	at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.addListener(AbstractFuture.java:134)
	at PluginClassLoader for workflow-support//org.jenkinsci.plugins.workflow.support.concurrent.Futures.addCallback(Futures.java:157)
	at PluginClassLoader for workflow-support//org.jenkinsci.plugins.workflow.support.concurrent.Futures.addCallback(Futures.java:97)
	at PluginClassLoader for workflow-cps//org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.runInCpsVmThread(CpsFlowExecution.java:987)
	at PluginClassLoader for workflow-cps//org.jenkinsci.plugins.workflow.cps.CpsStepContext.scheduleNextRun(CpsStepContext.java:388)
	at PluginClassLoader for workflow-cps//org.jenkinsci.plugins.workflow.cps.CpsStepContext.completed(CpsStepContext.java:326)
	at PluginClassLoader for workflow-cps//org.jenkinsci.plugins.workflow.cps.CpsStepContext.onSuccess(CpsStepContext.java:318)
	at PluginClassLoader for workflow-durable-task-step//org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.handleExit(DurableTaskStep.java:662)
	at PluginClassLoader for workflow-durable-task-step//org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.exited(DurableTaskStep.java:652)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:986)
	at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:961)
	at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:907)
	at hudson.remoting.UserRequest.perform(UserRequest.java:225)
	at hudson.remoting.UserRequest.perform(UserRequest.java:50)
	at hudson.remoting.Request$2.run(Request.java:391)
	at …
2025-06-23 18:40:13.298+0000 [id=170]	FINE	o.j.p.w.s.d.DurableTaskStep$Execution$NewlineSafeTaskListener$1#close: calling close with nl=true
2025-06-23 18:40:14.249+0000 [id=75]	INFO	o.j.p.w.s.d.e.FinishProcess#run: done, and slept a bit too
…restarted…
2025-06-23 18:40:17.247+0000 [id=157]	INFO	o.j.p.m.MockSlaveLauncher#launch: agent launched for remote
[p#1]    5.725 Resuming build at Mon Jun 23 14:40:17 EDT 2025 after Jenkins restart
[p#1]    5.725 Waiting for reconnection of remote before proceeding with build
2025-06-23 18:40:17.606+0000 [id=153]	FINE	o.j.p.d.FileMonitoringTask$FileMonitoringController#watch: started asynchronous watch in …/agent/workspace/p@tmp/durable-27c88019
java.lang.Throwable
	at PluginClassLoader for durable-task//org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.watch(FileMonitoringTask.java:554)
	at PluginClassLoader for workflow-durable-task-step//org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.getWorkspace(DurableTaskStep.java:381)
	at PluginClassLoader for workflow-durable-task-step//org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:576)
	at PluginClassLoader for workflow-durable-task-step//org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:559)
	at …
2025-06-23 18:40:17.719+0000 [id=153]	FINE	o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in …/agent/workspace/p on remote

…
+ set +x
Pausing (Preparing for shutdown)
Resuming build at Mon Jun 23 14:40:17 EDT 2025 after Jenkins restart
Waiting for reconnection of remote before proceeding with build
Ready to run at Mon Jun 23 14:40:17 EDT 2025
process apparently never started in …/agent/workspace/p@tmp/durable-27c88019
(running Jenkins temporarily with -Dorg.jenkinsci.plugins.durabletask.BourneShellScript.LAUNCH_DIAGNOSTICS=true might make the problem clearer)

Launching
<===[JENKINS REMOTING CAPACITY]===>channel started
Remoting version: 3261.v9c670a_4748a_9
Launcher: MockSlaveLauncher
Communication Protocol: Standard in/out
This is a Unix agent
Launched in 0s
Agent successfully connected and online
… PM org.jenkinsci.plugins.durabletask.FileMonitoringTask$Watcher run
WARNING: giving up on watching nonexistent …/agent/workspace/p@tmp/durable-…

CloudBees-internal issue

@jglick jglick added the bug label Jun 23, 2025
@jglick jglick marked this pull request as ready for review June 23, 2025 19:08
@jglick jglick requested a review from a team as a code owner June 23, 2025 19:08
@jglick jglick requested review from Vlatombe and dwnusbaum June 23, 2025 19:08
@jglick
Copy link
Member Author

jglick commented Jun 23, 2025 •
edited
Loading

https://github.com/jenkinsci/workflow-durable-task-step-plugin/pull/455/checks?check_run_id=44631343743 👀 locally on Windows 10 I consistently get a different error

[ERROR] org.jenkinsci.plugins.workflow.support.steps.ExecutorStepTest.restartWhilePlaceholderTaskIsInQueue[watching=true] -- Time elapsed: 22.44 s <<< FAILURE!
java.lang.AssertionError:
unexpected build status; build log was:
------
Started
[Pipeline] Start of Pipeline
[Pipeline] node
Running on custom-label in …\target\tmp\custom-label-work6203272964080007094\workspace\p
[Pipeline] {
[Pipeline] semaphore
Resuming build at Mon Jun 23 16:13:57 EDT 2025 after Jenkins restart
Waiting for reconnection of custom-label before proceeding with build
Resuming build at Mon Jun 23 16:14:01 EDT 2025 after Jenkins restart
Waiting for reconnection of custom-label before proceeding with build
Ready to run at Mon Jun 23 16:14:04 EDT 2025
[Pipeline] }
[Pipeline] // node
[Pipeline] End of Pipeline
Queue task was cancelled
org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 6b48a046-b4c0-49b4-8a5c-d59bf32ea404
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:1415)
        at org.jvnet.hudson.test.JenkinsRule.assertBuildStatusSuccess(JenkinsRule.java:1444)
        at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepTest.lambda$restartWhilePlaceholderTaskIsInQueue$45(ExecutorStepTest.java:1220)

@jglick jglick enabled auto-merge June 23, 2025 20:25
@jglick jglick merged commit 16e66c8 into jenkinsci:master Jun 23, 2025
16 of 17 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@dwnusbaum dwnusbaum dwnusbaum approved these changes

@Vlatombe Vlatombe Awaiting requested review from Vlatombe

Assignees

No one assigned

Labels

bug

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

2 participants

@jglick @dwnusbaum