Search code examples
jenkinsjenkins-pipelinecloudbees

Jenkins Build Timeout

I inherited a few Jenkins multi-branch pipeline builds

It's running Jenkins process to invoke msbuild (.net app)

I have not been able to find anything that wraps the build in a timeout step, but our build step fails after 5 minutes

What am I missing, how can I extend my build stage beyond 5 minutes?

I am at a complete loss, I was expecting to find something like timeout(5)... or the like, but haven't found anything

Update

Trimmed the build log:

10:50:58 running NUnit with timeout of 25 minutes
10:50:58 NUnit Console Runner 3.8.0
10:50:58 Copyright (c) 2018 Charlie Poole, Rob Prouse
10:50:58
10:50:58 Runtime Environment
10:50:58 OS Version: Microsoft Windows NT 6.2.9200.0
10:50:58 CLR Version: 4.0.30319.42000
10:50:58
... nunit output removed ...
10:54:49
10:56:02 NUnit execution timed out after 25 minutes
10:56:02 Message: null
10:56:02 StackTrace: java.lang.InterruptedException
10:56:02 at java.lang.ProcessImpl.waitFor(ProcessImpl.java:451)
10:56:02 at hudson.Proc$LocalProc.join(Proc.java:324)
10:56:02 at hudson.Proc.joinWithTimeout(Proc.java:170)
10:56:02 at com.mycompany.jenkins.plugins.nunit.NunitExecutor.run(NunitExecutor.java:79)
10:56:02 at com.mycompany.jenkins.plugins.BaseExecutor.start(BaseExecutor.java:35)
10:56:02 at org.jenkinsci.plugins.workflow.cps.DSL.invokeStep(DSL.java:229)
10:56:02 at org.jenkinsci.plugins.workflow.cps.DSL.invokeMethod(DSL.java:153)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsScript.invokeMethod(CpsScript.java:122)
10:56:02 at sun.reflect.GeneratedMethodAccessor463.invoke(Unknown Source)
10:56:02 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
10:56:02 at java.lang.reflect.Method.invoke(Method.java:498)
10:56:02 at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
10:56:02 at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
10:56:02 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1213)
10:56:02 at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
10:56:02 at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:42)
10:56:02 at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
10:56:02 at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
10:56:02 at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:157)
10:56:02 at org.kohsuke.groovy.sandbox.GroovyInterceptor.onMethodCall(GroovyInterceptor.java:23)
10:56:02 at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onMethodCall(SandboxInterceptor.java:133)
10:56:02 at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onMethodCall(SandboxInterceptor.java:120)
10:56:02 at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:155)
10:56:02 at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:159)
10:56:02 at com.cloudbees.groovy.cps.sandbox.SandboxInvoker.methodCall(SandboxInvoker.java:17)
10:56:02 at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:57)
10:56:02 at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
10:56:02 at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
10:56:02 at sun.reflect.GeneratedMethodAccessor426.invoke(Unknown Source)
10:56:02 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
10:56:02 at java.lang.reflect.Method.invoke(Method.java:498)
10:56:02 at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
10:56:02 at com.cloudbees.groovy.cps.impl.CollectionLiteralBlock$ContinuationImpl.dispatch(CollectionLiteralBlock.java:55)
10:56:02 at com.cloudbees.groovy.cps.impl.CollectionLiteralBlock$ContinuationImpl.item(CollectionLiteralBlock.java:45)
10:56:02 at sun.reflect.GeneratedMethodAccessor453.invoke(Unknown Source)
10:56:02 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
10:56:02 at java.lang.reflect.Method.invoke(Method.java:498)
10:56:02 at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
10:56:02 at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
10:56:02 at com.cloudbees.groovy.cps.Next.step(Next.java:83)
10:56:02 at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:174)
10:56:02 at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:163)
10:56:02 at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:122)
10:56:02 at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:261)
10:56:02 at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:163)
10:56:02 at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$101(SandboxContinuable.java:34)
10:56:02 at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.lambda$run0$0(SandboxContinuable.java:59)
10:56:02 at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox.runInSandbox(GroovySandbox.java:108)
10:56:02 at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:58)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:174)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:332)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$200(CpsThreadGroup.java:83)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:244)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:232)
10:56:02 at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:64)
10:56:02 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
10:56:02 at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:112)
10:56:02 at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
10:56:02 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
10:56:02 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
10:56:02 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
10:56:02 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
10:56:02 at java.lang.Thread.run(Thread.java:745)

The two areas of code that it references in exception above

NunitExecutor.run(NunitExecutor.java:79), extends BaseExecutor:

TaskListener listener ...

final Launcher.ProcStarter starter = launcher.launch().cmds(args).stdout(listener.getLogger()).stderr(listener.getLogger()).envs(env).pwd(ws);
Proc process = null;

try
{
    // step is an obj that extends Jenkins worfklow Step
    listener.getLogger().println("running NUnit with timeout of " + step.timeOut + " minutes");
    process = starter.start();
    final int exitCode = process.joinWithTimeout(timeOut, TimeUnit.MINUTES, listener);  --line 79

BaseExecutor.start(BaseExecutor.java:35), BaseExecutor extends StepExecution:

@Override
public boolean start() throws Exception {
    try {
        getContext().onSuccess(run());  -- line 35

value timeOut = 25

if the stage runs for less than 5 mins, this works fine, but if it runs longer than 5 mins, it fails with timeout, even though we are saying wait for 25 mins

Solution

  • Problem is due to Jenkins introducing a hard timeout on Steps https://issues.jenkins-ci.org/browse/JENKINS-42561 and https://issues.jenkins-ci.org/browse/JENKINS-47006

    Our custom build pipeline extends Steps to perform build custom functions, solution seems to be to move away from Step and use DurableStep instead