| << Back to previous view |
|
[QB-3108] Build timeout does not work on build running a command line in combination with force kill
|
|
| Status: | Closed |
| Project: | QuickBuild |
| Component/s: | None |
| Affects Version/s: | 7.0.30 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Critical |
| Reporter: | AlSt | Assigned To: | Robin Shen |
| Resolution: | Fixed | Votes: | 0 |
| Remaining Estimate: | Unknown | Time Spent: | Unknown |
| Original Estimate: | Unknown | ||
| Description |
|
Following situation:
Build with * Checkout step * Gradle build step Build timeout: 25 minutes Force kill timeout: 60 seconds Build times out and the "Terminating launched command gracefully..." log line appears. Graceful termination takes longer than 60 seconds -> Force kill is not triggered. After approx 50 minutes (after the graceful kill log line was shown) the cancel button is pressed because the build should have been stopped already for 49 minutes or so (after the force kill timeout expired). Now the "Unable to terminate launched command gracefully, terminating forcibly instead..." log line appears. I took a look at the source code and I think I know what's the problem there: com/pmease/quickbuild/execution/Commandline.java: Lines 350-378: InterruptedException interruptedException = null; try { result.setReturnCode(process.waitFor()); } catch (InterruptedException e) { interruptedException = e; Context.getLogger().info("Terminating launched command gracefully..."); terminateProcessTree(process, session, false); } long lastTime = System.currentTimeMillis(); Configuration configuration = Context.getConfiguration(); int forceKillTimeout; if (configuration != null) forceKillTimeout = configuration.findForceKillTimeout(); else forceKillTimeout = 5; while (!streamPumper.closed()) { try { Thread.sleep(100); } catch (InterruptedException e) { if (System.currentTimeMillis() - lastTime > forceKillTimeout*1000L) { Context.getLogger().info("Unable to terminate launched command gracefully, terminating forcibly instead..."); terminateProcessTree(process, session, true); lastTime = System.currentTimeMillis(); } } } The problem is that the interruption state is not preserved... Thread.sleep() resets the interruption state of the current thread and also the second InterruptedException is never thrown automatically. That's why the manual click of the cancel button solves that as the interruptedexception is thrown again. The fix should be putting if (System.currentTimeMillis() - lastTime > forceKillTimeout*1000L) { Context.getLogger().info("Unable to terminate launched command gracefully, terminating forcibly instead..."); terminateProcessTree(process, session, true); lastTime = System.currentTimeMillis(); } outside the catch block to check it always. I think the whole code example should be changed to something like: InterruptedException interruptedException = null; try { result.setReturnCode(process.waitFor()); } catch (InterruptedException e) { interruptedException = e; Context.getLogger().info("Terminating launched command gracefully..."); terminateProcessTree(process, session, false); long lastTime = System.currentTimeMillis(); Configuration configuration = Context.getConfiguration(); int forceKillTimeout; if (configuration != null) forceKillTimeout = configuration.findForceKillTimeout(); else forceKillTimeout = 5; while (!streamPumper.closed()) { try { Thread.sleep(100); } catch (InterruptedException e) { } if (System.currentTimeMillis() - lastTime > forceKillTimeout*1000L) { Context.getLogger().info("Unable to terminate launched command gracefully, terminating forcibly instead..."); terminateProcessTree(process, session, true); lastTime = System.currentTimeMillis(); } } } Then the first interruptedexception is caught... the graceful terminate is triggered... the streamPumper state is checked periodically and if the forceKillTimeout is reached -> the force kill is triggered. Please share your thoughts on this, but I think this is the solution for this problem. |
| Comments |
| Comment by Robin Shen [ 28/Dec/17 10:15 PM ] |
|
Thanks for the investigation. That is really the problem. Changed your suggestion slightly to make QB always trying to terminate gracefully before force kill:
InterruptedException interruptedException = null; try { result.setReturnCode(process.waitFor()); } catch (InterruptedException e) { interruptedException = e; Context.getLogger().info("Terminating launched command gracefully..."); terminateProcessTree(process, session, false); } long lastTime = System.currentTimeMillis(); Configuration configuration = Context.getConfiguration(); int forceKillTimeout; if (configuration != null) forceKillTimeout = configuration.findForceKillTimeout(); else forceKillTimeout = 5; while (!streamPumper.closed()) { try { Thread.sleep(100); } catch (InterruptedException e) { if (interruptedException == null) { // if not interrupted before, try a graceful kill interruptedException = e; Context.getLogger().info("Terminating launched command gracefully..."); terminateProcessTree(process, session, false); lastTime = System.currentTimeMillis(); } } if (interruptedException != null && System.currentTimeMillis() - lastTime > forceKillTimeout*1000L) { Context.getLogger().info("Unable to terminate launched command gracefully, terminating forcibly instead..."); terminateProcessTree(process, session, true); lastTime = System.currentTimeMillis(); } } |
| Comment by AlSt [ 29/Dec/17 06:58 AM ] |
| Looks like the way to go :-) |