Skip to content
Permalink
Browse files

[JENKINS-39072] In case a timeout fails to kill its block normally, t…

…ry forcibly killing the innermost step, akin to doTerm.

Does not suffice to kill the body in all cases.
  • Loading branch information
jglick committed Oct 24, 2016
1 parent 5c13f4f commit 040ed79ce10f7fc7b1c93562d4211db7e470486f
@@ -1,27 +1,41 @@
package org.jenkinsci.plugins.workflow.steps;

import com.google.common.util.concurrent.ListenableFuture;
import com.google.common.util.concurrent.MoreExecutors;
import com.google.inject.Inject;
import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
import hudson.Main;
import hudson.Util;
import hudson.model.Result;
import hudson.model.TaskListener;
import java.io.IOException;
import java.util.List;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.TimeUnit;

import java.util.logging.Level;
import java.util.logging.Logger;
import jenkins.model.CauseOfInterruption;
import jenkins.util.Timer;
import org.jenkinsci.plugins.workflow.flow.FlowExecution;
import org.jenkinsci.plugins.workflow.graph.FlowNode;
import org.jenkinsci.plugins.workflow.graphanalysis.LinearBlockHoppingScanner;

/**
* @author Kohsuke Kawaguchi
*/
@SuppressFBWarnings("SE_INNER_CLASS")
public class TimeoutStepExecution extends AbstractStepExecutionImpl {

private static final Logger LOGGER = Logger.getLogger(TimeoutStepExecution.class.getName());
private static final long GRACE_PERIOD = Main.isUnitTest ? /* 5s */5_000 : /* 1m */60_000;

@Inject(optional=true)
private transient TimeoutStep step;
@StepContextParameter private transient TaskListener listener;
private BodyExecution body;
private transient ScheduledFuture<?> killer;

private long end = 0;
/** whether we are forcing the body to end */
private boolean forcible;

@Override
public boolean start() throws Exception {
@@ -49,7 +63,9 @@ public void onResume() {
private void setupTimer(final long now) {
if (end > now) {
long delay = end - now;
listener.getLogger().println("Timeout set to expire in " + Util.getTimeSpanString(delay));
if (!forcible) {
listener.getLogger().println("Timeout set to expire in " + Util.getTimeSpanString(delay));
}
killer = Timer.get().schedule(new Runnable() {
@Override
public void run() {
@@ -62,8 +78,52 @@ public void run() {
}

private void cancel() {
listener.getLogger().println("Cancelling nested steps due to timeout");
body.cancel(new ExceededTimeout());
if (forcible) {
if (!killer.isCancelled()) {
listener.getLogger().println("Body did not finish within grace period; terminating with extreme prejudice");
FlowExecution exec;
try {
exec = getContext().get(FlowExecution.class);
} catch (IOException | InterruptedException x) {
LOGGER.log(Level.WARNING, null, x);
return;
}
final Throwable death = new FlowInterruptedException(Result.ABORTED, new ExceededTimeout());
/* Due to JENKINS-25504, this does not accomplish anything beyond what the original body.cancel would have:
getContext().onFailure(death);
*/
final ListenableFuture<List<StepExecution>> currentExecutions = exec.getCurrentExecutions(true);
// TODO would use Futures.addCallback but this is still @Beta in Guava 19 and the Pipeline copy is in workflow-support on which we have no dep
currentExecutions.addListener(new Runnable() {
@Override public void run() {
assert currentExecutions.isDone();
try {
FlowNode outer = getContext().get(FlowNode.class); // timeout
for (StepExecution exec : currentExecutions.get()) {
FlowNode inner = exec.getContext().get(FlowNode.class); // some deadbeat step, perhaps
LinearBlockHoppingScanner scanner = new LinearBlockHoppingScanner();
scanner.setup(inner);
for (FlowNode enclosing : scanner) {
if (enclosing.equals(outer)) {
exec.getContext().onFailure(death);
break;
}
}
}
} catch (IOException | InterruptedException | ExecutionException x) {
LOGGER.log(Level.WARNING, null, x);
}
}
}, MoreExecutors.sameThreadExecutor());
}
} else {
listener.getLogger().println("Cancelling nested steps due to timeout");
body.cancel(new ExceededTimeout());
forcible = true;
long now = System.currentTimeMillis();
end = now + GRACE_PERIOD;
setupTimer(now);
}
}

@Override
@@ -25,6 +25,9 @@
package org.jenkinsci.plugins.workflow.steps;

import hudson.model.Result;
import hudson.model.TaskListener;
import java.util.List;
import java.util.concurrent.TimeUnit;
import jenkins.model.CauseOfInterruption;
import jenkins.model.InterruptedBuildAction;
import org.jenkinsci.plugins.workflow.actions.ErrorAction;
@@ -36,14 +39,13 @@
import org.jenkinsci.plugins.workflow.support.visualization.table.FlowGraphTable.Row;
import org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep;
import org.junit.*;
import static org.junit.Assert.assertEquals;
import org.junit.runners.model.Statement;
import org.jvnet.hudson.test.BuildWatcher;
import org.jvnet.hudson.test.Issue;
import org.jvnet.hudson.test.RestartableJenkinsRule;

import java.util.List;
import java.util.concurrent.TimeUnit;
import static org.junit.Assert.assertEquals;
import org.jvnet.hudson.test.TestExtension;
import org.kohsuke.stapler.DataBoundConstructor;

public class TimeoutStepTest extends Assert {

@@ -198,6 +200,49 @@ public void evaluate() throws Throwable {
});
}

@Issue("JENKINS-39072")
@Test public void unresponsiveBody() {
story.addStep(new Statement() {
@Override public void evaluate() throws Throwable {
WorkflowJob p = story.j.jenkins.createProject(WorkflowJob.class, "p");
p.setDefinition(new CpsFlowDefinition("timeout(time: 2, unit: 'SECONDS') {unkillable()}", true));
story.j.assertBuildStatus(Result.ABORTED, p.scheduleBuild2(0).get());
}
});
}
public static class UnkillableStep extends AbstractStepImpl {
@DataBoundConstructor public UnkillableStep() {}
public static class Execution extends AbstractStepExecutionImpl {
@StepContextParameter transient TaskListener listener;
@Override public boolean start() throws Exception {
return false;
}
@Override public void stop(Throwable cause) throws Exception {
listener.getLogger().println("ignoring " + cause);
}
}
@TestExtension("unresponsiveBody") public static class DescriptorImpl extends AbstractStepDescriptorImpl {
public DescriptorImpl() {
super(Execution.class);
}
@Override public String getFunctionName() {
return "unkillable";
}
}
}

@Ignore("TODO cannot find any way to solve this case")
@Issue("JENKINS-39072")
@Test public void veryUnresponsiveBody() {
story.addStep(new Statement() {
@Override public void evaluate() throws Throwable {
WorkflowJob p = story.j.jenkins.createProject(WorkflowJob.class, "p");
p.setDefinition(new CpsFlowDefinition("timeout(time: 2, unit: 'SECONDS') {while (true) {try {sleep 10} catch (e) {echo(/ignoring ${e}/)}}}", true));
story.j.assertBuildStatus(Result.ABORTED, p.scheduleBuild2(0).get());
}
});
}

// TODO: timeout inside parallel

}

0 comments on commit 040ed79

Please sign in to comment.
You can’t perform that action at this time.