[JENKINS-59793] Avoid hanging jobs with faulty SubTasks #4346

MRamonLeon · 2019-11-07T17:00:20Z

I have created a test to reproduce the status reached by several private Jenkins instances which have thousand of Metric Plugin threads (QueueSubTaskMetrics) running. It's all because if a Job has faulty SubTasks (throwing an unmanaged exception), the future object is not set in the WorkUnitContext#synchronizeEnd method. It may also happen in WorkUnitContext#synchronizeStart but I have not reproduced this case).

Whatever code that keeps waiting for the start or the end of the build will stay there forever. The Metrics Plugin is impacted by this here:

Waiting for the build to finish: https://github.com/jenkinsci/metrics-plugin/blob/24bf92ebd59095d8f77b2552696b3f210a024bdc/src/main/java/jenkins/metrics/impl/JenkinsMetricProviderImpl.java#L1142

Called from: https://github.com/jenkinsci/metrics-plugin/blob/24bf92ebd59095d8f77b2552696b3f210a024bdc/src/main/java/jenkins/metrics/impl/JenkinsMetricProviderImpl.java#L944

I will let the CI fail and then I will push the fix.

Proposed changelog entries

Entry 1: Improve the resilience to faulty subtask contributors which may keep the build running forever.

Submitter checklist

JIRA issue is well described
Changelog entry appropriate for the audience affected by the change (users or developer, depending on the change). Examples
* Use the Internal: prefix if the change has no user-visible impact (API, test frameworks, etc.)
Appropriate autotests or explanation to why this change has no tests
[N/A] For dependency updates: links to external changelogs and, if possible, full diffs

Desired reviewers

@daniel-beck @varyvol @batmat @alecharp @rsandell @fcojfernandez @stephenc

…'t stop

MRamonLeon · 2019-11-07T19:52:55Z

The failure in the new test without the fix in the code: https://ci.jenkins.io/blue/organizations/jenkins/Core%2Fjenkins/detail/PR-4346/1/tests

Stacktrace
java.util.concurrent.TimeoutException
	at hudson.remoting.AsyncFutureImpl.get(AsyncFutureImpl.java:97)
	at hudson.model.queue.BuildKeepsRunningWhenFaultySubTasksTest.buildDoesntFinishWhenSubTaskFails(BuildKeepsRunningWhenFaultySubTasksTest.java:46)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.jvnet.hudson.test.JenkinsRule$1.evaluate(JenkinsRule.java:600)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.lang.Thread.run(Thread.java:834)
...
  10.292 [id=32]	SEVERE	hudson.model.Executor#finish1: Executor threw an exception
java.lang.ArrayIndexOutOfBoundsException: My unexpected exception
	at hudson.model.queue.BuildKeepsRunningWhenFaultySubTasksTest$FailingSubTaskContributor$1$1.run(BuildKeepsRunningWhenFaultySubTasksTest.java:65)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:427)

res0nance

LGTM 👍

varyvol

For all reviews, note this issue has been happening also in http://ci.jenkins.io

@MRamonLeon my doubt here is: why has the issue has started appearing now? The metrics plugin does not seem to have important changes related to this.

varyvol · 2019-11-08T08:44:04Z

test/src/test/java/hudson/model/queue/BuildKeepsRunningWhenFaultySubTasksTest.java

+
+        // We get stalled waiting the finalization of the job
+        FreeStyleBuild build = future.get(5, TimeUnit.SECONDS);
+        assertTrue("The message is printed in the log", logs.getRecords().stream().anyMatch(r -> r.getThrown().getMessage().equals(ERROR_MESSAGE)));


Not sure this is really necessary (reaching this point would be enough to assert the fix?) and you could save all the logger rules.

Yes, not needed if the code passes the get. It's a reminiscence from a lot of tests I've been doing. I can remove it.

varyvol · 2019-11-08T08:44:48Z

test/src/test/java/hudson/model/queue/BuildKeepsRunningWhenFaultySubTasksTest.java

+    // When using SubTaskContributor (FailingSubTaskContributor) the build never ends
+    @Test
+    @Issue("JENKINS-59793")
+    public void buildDoesntFinishWhenSubTaskFails() throws Exception {


Suggested change

public void buildDoesntFinishWhenSubTaskFails() throws Exception {

public void buildFinishesWhenSubTaskFails() throws Exception {

I think the name is appropriate before the fix but after the fix it should say what's actually asserting.

Pushed with the other change

varyvol · 2019-11-08T08:44:58Z

test/src/test/java/hudson/model/queue/BuildKeepsRunningWhenFaultySubTasksTest.java

+        assertThat("Build should be actually scheduled by Jenkins", future, notNullValue());
+
+        // We get stalled waiting the finalization of the job
+        FreeStyleBuild build = future.get(5, TimeUnit.SECONDS);


Should you also check the build result is a failure?

No need to assert that, the purpose of the test is to guarantee we pass this point, so let's keep the minimum needed as agreed above.

stephenc

Some suggestions for even more robustness and perhaps covering another edge case.

Your change makes things better (hence approving) so if you would rather merge your change first to get an improvement out and then examine my proposal in a subsequent PR that's totally fine

core/src/main/java/hudson/model/queue/WorkUnitContext.java

Co-authored-by: Stephen Connolly <stephen.alan.connolly@gmail.com>

MRamonLeon · 2019-11-11T11:52:47Z

Added @stephenc's suggestions

stephenc

LGTM

core/src/main/java/hudson/model/queue/WorkUnitContext.java

MRamonLeon · 2019-11-12T11:47:06Z

I had to roll back to the original fix because the test was failing. Jenkins was shutting down after an unexpected exception in the test. I couldn't figure out why it was happening, so better we let this PR get merged and we improve it in a followup PR if desired.

oleg-nenashev · 2019-11-12T16:22:31Z

I plan to merge it tomorrow if no negative feedback

batmat · 2019-11-13T08:52:26Z

OK, moving on given no negative feedback since yesterday.

Thank you eveyone!

[JENKINS-59793] Avoid hanging jobs with faulty SubTasks (cherry picked from commit 5f81077)

[JENKINS-59793] A test showing how a build with faulty SubTasks doesn…

b4be12d

…'t stop

MRamonLeon requested review from varyvol, rsandell, daniel-beck, fcojfernandez, batmat, stephenc and alecharp November 7, 2019 17:01

MRamonLeon added the bug For changelog: Minor bug. Will be listed after features label Nov 7, 2019

[FNDJEN-59793] Ensure the future is always set

30e51c4

res0nance approved these changes Nov 8, 2019

View reviewed changes

varyvol reviewed Nov 8, 2019

View reviewed changes

[FNDJEN-59793] Change test name and avoid extra assertions

5b4799a

varyvol approved these changes Nov 8, 2019

View reviewed changes

MRamonLeon added the needs-more-reviews Complex change, which would benefit from more eyes label Nov 8, 2019

timja approved these changes Nov 10, 2019

View reviewed changes

stephenc approved these changes Nov 11, 2019

View reviewed changes

oleg-nenashev removed the needs-more-reviews Complex change, which would benefit from more eyes label Nov 11, 2019

[FNDJEN-59793] Change test name and avoid extra assertions

d96ac81

Co-authored-by: Stephen Connolly <stephen.alan.connolly@gmail.com>

stephenc approved these changes Nov 11, 2019

View reviewed changes

varyvol reviewed Nov 11, 2019

View reviewed changes

core/src/main/java/hudson/model/queue/WorkUnitContext.java Show resolved Hide resolved

MRamonLeon added 2 commits November 11, 2019 17:50

[FNDJEN-59793] Ensure the new exceptions thrown set the future as well

cff8546

[FNDJEN-59793] Rollback to original fix plus NoExternalUse

5fb44bd

rsandell approved these changes Nov 12, 2019

View reviewed changes

MRamonLeon added the ready-for-merge The PR is ready to go, and it will be merged soon if there is no negative feedback label Nov 12, 2019

batmat merged commit 5f81077 into jenkinsci:master Nov 13, 2019

MRamonLeon deleted the JENKINS-59793 branch November 18, 2019 10:30

MRamonLeon mentioned this pull request Nov 21, 2019

[JENKINS-57304] - Add call to oneOffExecutors.remove in Computer.removeExecutor #4329

Merged

olivergondza pushed a commit that referenced this pull request Nov 26, 2019

Merge pull request #4346 from MRamonLeon/JENKINS-59793

b4d19ab

[JENKINS-59793] Avoid hanging jobs with faulty SubTasks (cherry picked from commit 5f81077)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[JENKINS-59793] Avoid hanging jobs with faulty SubTasks #4346

[JENKINS-59793] Avoid hanging jobs with faulty SubTasks #4346

MRamonLeon commented Nov 7, 2019 •

edited

Loading

MRamonLeon commented Nov 7, 2019 •

edited

Loading

res0nance left a comment

varyvol left a comment

varyvol Nov 8, 2019

MRamonLeon Nov 8, 2019

varyvol Nov 8, 2019

MRamonLeon Nov 8, 2019

varyvol Nov 8, 2019

MRamonLeon Nov 8, 2019

stephenc left a comment

MRamonLeon commented Nov 11, 2019 •

edited

Loading

stephenc left a comment

MRamonLeon commented Nov 12, 2019

oleg-nenashev commented Nov 12, 2019

batmat commented Nov 13, 2019 •

edited

Loading

	public void buildDoesntFinishWhenSubTaskFails() throws Exception {
	public void buildFinishesWhenSubTaskFails() throws Exception {

[JENKINS-59793] Avoid hanging jobs with faulty SubTasks #4346

[JENKINS-59793] Avoid hanging jobs with faulty SubTasks #4346

Conversation

MRamonLeon commented Nov 7, 2019 • edited Loading

Proposed changelog entries

Submitter checklist

Desired reviewers

MRamonLeon commented Nov 7, 2019 • edited Loading

res0nance left a comment

Choose a reason for hiding this comment

varyvol left a comment

Choose a reason for hiding this comment

varyvol Nov 8, 2019

Choose a reason for hiding this comment

MRamonLeon Nov 8, 2019

Choose a reason for hiding this comment

varyvol Nov 8, 2019

Choose a reason for hiding this comment

MRamonLeon Nov 8, 2019

Choose a reason for hiding this comment

varyvol Nov 8, 2019

Choose a reason for hiding this comment

MRamonLeon Nov 8, 2019

Choose a reason for hiding this comment

stephenc left a comment

Choose a reason for hiding this comment

MRamonLeon commented Nov 11, 2019 • edited Loading

stephenc left a comment

Choose a reason for hiding this comment

MRamonLeon commented Nov 12, 2019

oleg-nenashev commented Nov 12, 2019

batmat commented Nov 13, 2019 • edited Loading

MRamonLeon commented Nov 7, 2019 •

edited

Loading

MRamonLeon commented Nov 7, 2019 •

edited

Loading

MRamonLeon commented Nov 11, 2019 •

edited

Loading

batmat commented Nov 13, 2019 •

edited

Loading