Merge pull request #249 from jenkinsci/JENKINS-29705

[JENKINS-29705] Added thread dump support
jenkinsci · Nov 25, 2015 · 2ac2149 · 2ac2149
2 parents 8dd67dd + aae9954
commit 2ac2149
Show file tree

Hide file tree

Showing 13 changed files with 514 additions and 19 deletions.
diff --git a/CHANGES.md b/CHANGES.md
@@ -4,6 +4,7 @@ Only noting significant user changes, not internal code cleanups and minor bug f
 
 ## 1.12 (upcoming)
 
+* [JENKINS-29705](https://issues.jenkins-ci.org/browse/JENKINS-29705): added _Thread Dump_ link to running flow builds for diagnosing problems like hangs.
 * [JENKINS-31649](https://issues.jenkins-ci.org/browse/JENKINS-31649): correctly display pending queue items for blocked `node {}` tasks when on Jenkins 1.639+ (will not appear in 1.638 or 1.625.2).
 * [JENKINS-31691](https://issues.jenkins-ci.org/browse/JENKINS-31691): added `isUnix` step.
 * [JENKINS-31585](https://issues.jenkins-ci.org/browse/JENKINS-31585): make new script editor resizable.

diff --git a/aggregator/src/test/java/org/jenkinsci/plugins/workflow/cps/CpsThreadDumpTest.java b/aggregator/src/test/java/org/jenkinsci/plugins/workflow/cps/CpsThreadDumpTest.java
@@ -0,0 +1,140 @@
+package org.jenkinsci.plugins.workflow.cps;
+
+import java.util.ArrayList;
+import static java.util.Arrays.asList;
+import java.util.List;
+import org.apache.commons.lang.StringUtils;
+import org.jenkinsci.plugins.workflow.cps.CpsThreadDump.ThreadInfo;
+import org.jenkinsci.plugins.workflow.job.WorkflowJob;
+import org.jenkinsci.plugins.workflow.job.WorkflowRun;
+import org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep;
+import static org.junit.Assert.*;
+import org.junit.Before;
+import org.junit.ClassRule;
+import org.junit.Rule;
+import org.junit.Test;
+import org.jvnet.hudson.test.BuildWatcher;
+import org.jvnet.hudson.test.JenkinsRule;
+
+public class CpsThreadDumpTest {
+
+    @ClassRule public static BuildWatcher buildWatcher = new BuildWatcher();
+    @Rule
+    public JenkinsRule j = new JenkinsRule();
+    private WorkflowJob p;
+
+    @Before
+    public void setUp() throws Exception {
+        p = j.jenkins.createProject(WorkflowJob.class, "p");
+    }
+
+    @Test
+    public void simple() throws Exception {
+        p.setDefinition(new CpsFlowDefinition(StringUtils.join(asList(
+                "def foo() { bar() }",
+                "def bar() {",
+                "   semaphore 'x'",
+                "}",
+                "foo()"
+        ), "\n")));
+        WorkflowRun b = p.scheduleBuild2(0).waitForStart();
+        SemaphoreStep.waitForStart("x/1", b);
+        CpsThreadDump td = b.getAction(CpsThreadDumpAction.class).threadDumpSynchronous();
+        td.print(System.out);
+
+        {// verify that we got the right thread dump
+            List<ThreadInfo> threads = td.getThreads();
+            assertEquals(1, threads.size());
+            ThreadInfo t = threads.get(0);
+            assertEquals("Thread #0", t.getHeadline());
+            assertStackTrace(t,
+                    "DSL.semaphore(Native Method)",
+                    "WorkflowScript.bar(WorkflowScript:3)",
+                    "WorkflowScript.foo(WorkflowScript:1)",
+                    "WorkflowScript.run(WorkflowScript:5)");
+        }
+        SemaphoreStep.success("x/1", null);
+        j.waitForCompletion(b);
+        assertNull(b.getAction(CpsThreadDumpAction.class));
+    }
+
+    @Test
+    public void parallel() throws Exception {
+        p.setDefinition(new CpsFlowDefinition(StringUtils.join(asList(
+                "def foo(x) { bar(x) }",// 1
+                "def bar(x) {",
+                "   semaphore x",       // 3
+                "}",
+                "def zot() {",
+                "  parallel(",          // 6
+                "    b1:{ foo('x') },",
+                "    b2:{ bar('y') });",
+                "}",
+                "zot()"                 // 10
+        ), "\n")));
+        WorkflowRun b = p.scheduleBuild2(0).waitForStart();
+        SemaphoreStep.waitForStart("x/1", b);
+        SemaphoreStep.waitForStart("y/1", b);
+
+        CpsThreadDump td = b.getAction(CpsThreadDumpAction.class).threadDumpSynchronous();
+        td.print(System.out);
+
+        assertStackTrace( td.getThreads().get(0),
+            "DSL.semaphore(Native Method)",
+            "WorkflowScript.bar(WorkflowScript:3)",
+            "WorkflowScript.foo(WorkflowScript:1)",
+            "WorkflowScript.zot(WorkflowScript:7)",
+            "DSL.parallel(Native Method)",
+            "WorkflowScript.zot(WorkflowScript:6)",
+            "WorkflowScript.run(WorkflowScript:10)");
+
+        assertStackTrace( td.getThreads().get(1),
+            "DSL.semaphore(Native Method)",
+            "WorkflowScript.bar(WorkflowScript:3)",
+            "WorkflowScript.zot(WorkflowScript:8)");
+    }
+
+    @Test public void load() throws Exception {
+        j.jenkins.getWorkspaceFor(p).child("lib.groovy").write("def m() {semaphore 'here'}; this", null);
+        p.setDefinition(new CpsFlowDefinition("def lib; node {lib = load 'lib.groovy'}; lib.m()", true));
+        WorkflowRun b = p.scheduleBuild2(0).waitForStart();
+        SemaphoreStep.waitForStart("here/1", b);
+        CpsThreadDump td = b.getAction(CpsThreadDumpAction.class).threadDumpSynchronous();
+        td.print(System.out);
+        assertStackTrace(td.getThreads().get(0),
+            "DSL.semaphore(Native Method)",
+            "Script1.m(Script1.groovy:1)",
+            "WorkflowScript.run(WorkflowScript:1)");
+    }
+
+    @Test public void nativeMethods() throws Exception {
+        p.setDefinition(new CpsFlowDefinition(
+            "@NonCPS def untransformed() {Thread.sleep(Long.MAX_VALUE)}\n" +
+            "def helper() {echo 'sleeping'; /* flush output */ sleep 1; untransformed()}\n" +
+            "helper()"));
+        WorkflowRun b = p.scheduleBuild2(0).waitForStart();
+        CpsFlowExecution e = (CpsFlowExecution) b.getExecutionPromise().get();
+        j.waitForMessage("sleeping", b);
+        do { // wait for the CPS VM to be busy (opposite of waitForSuspension)
+            Thread.sleep(100);
+        } while (!e.blocksRestart());
+        CpsThreadDump td = e.getThreadDump();
+        td.print(System.out);
+        assertStackTrace(td.getThreads().get(0),
+            // TODO would like to see untransformed and Thread.sleep here
+            "WorkflowScript.helper(WorkflowScript:2)",
+            "WorkflowScript.run(WorkflowScript:3)");
+        b.doKill();
+    }
+
+    private void assertStackTrace(ThreadInfo t, String... expected) {
+        assertEquals(asList(expected), toString(t.getStackTrace()));
+    }
+
+    private List<String> toString(List<StackTraceElement> in) {
+        List<String> r = new ArrayList<String>();
+        for (StackTraceElement e : in)
+            r.add(e.toString());
+        return r;
+    }
+}
diff --git a/api/src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionOwner.java b/api/src/main/java/org/jenkinsci/plugins/workflow/flow/FlowExecutionOwner.java
@@ -24,31 +24,45 @@
 
 package org.jenkinsci.plugins.workflow.flow;
 
-import hudson.model.Queue.Executable;
+import hudson.model.Queue;
 import hudson.model.Run;
-
-import javax.annotation.Nonnull;
 import java.io.File;
 import java.io.IOException;
-import java.io.PrintStream;
 import java.io.Serializable;
+import java.util.logging.Level;
+import java.util.logging.Logger;
+import javax.annotation.CheckForNull;
+import javax.annotation.Nonnull;
+import jenkins.model.TransientActionFactory;
 
 /**
  * We need something that's serializable in small moniker that helps us find THE instance
  * of {@link FlowExecution}.
- *
- * @author Jesse Glick
- * @author Kohsuke Kawaguchi
  */
-// this gets implemented by whoever that owns FlowExecution, like WorfklowRun
 public abstract class FlowExecutionOwner implements Serializable {
+
+    private static final Logger LOGGER = Logger.getLogger(FlowExecutionOwner.class.getName());
+
     /**
      * @throws IOException
      *      if fails to find {@link FlowExecution}.
      */
     @Nonnull
     public abstract FlowExecution get() throws IOException;
 
+    /**
+     * Same as {@link #get} but avoids throwing an exception or blocking.
+     * @return a valid flow execution, or null if not ready or invalid
+     */
+    public @CheckForNull FlowExecution getOrNull() {
+        try {
+            return get();
+        } catch (IOException x) {
+            LOGGER.log(Level.WARNING, null, x);
+            return null;
+        }
+    }
+
     /**
      * A directory (on the master) where information may be persisted.
      * @see Run#getRootDir
@@ -61,8 +75,9 @@ public abstract class FlowExecutionOwner implements Serializable {
      *
      * (For anything that runs for a long enough time that demands flow, it better occupies an executor.
      * So this type restriction should still enable scriptler to use this.)
+     * @return preferably an {@link Executable}
      */
-    public abstract Executable getExecutable() throws IOException;
+    public abstract Queue.Executable getExecutable() throws IOException;
 
     /**
      * Returns the URL of the model object that owns {@link FlowExecution},
@@ -92,4 +107,19 @@ public String getUrlOfExecution() throws IOException {
      */
     @Override
     public abstract int hashCode();
+
+    /**
+     * Marker interface for queue executables from {@link #getExecutable}.
+     * A reasonable target type for {@link TransientActionFactory}.
+     */
+    public interface Executable extends Queue.Executable {
+
+        /**
+         * Gets the associated owner moniker.
+         * @return the owner, or null if this instance is somehow inapplicable
+         */
+        @CheckForNull FlowExecutionOwner asFlowExecutionOwner();
+
+    }
+
 }
diff --git a/cps/src/main/java/org/jenkinsci/plugins/workflow/cps/CpsBodyExecution.java b/cps/src/main/java/org/jenkinsci/plugins/workflow/cps/CpsBodyExecution.java
@@ -173,7 +173,7 @@ private Continuable createContinuable(CpsThread currentThread, CpsCallableInvoca
         return new Continuable(
             // this source location is a place holder for the step implementation.
             // perhaps at some point in the future we'll let the Step implementation control this.
-            inv.invoke(env, SourceLocation.UNKNOWN, onSuccess));
+            inv.invoke(env, null, onSuccess));
     }
 
     @Override

diff --git a/cps/src/main/java/org/jenkinsci/plugins/workflow/cps/CpsFlowExecution.java b/cps/src/main/java/org/jenkinsci/plugins/workflow/cps/CpsFlowExecution.java
@@ -104,6 +104,7 @@
 import org.acegisecurity.Authentication;
 import org.acegisecurity.userdetails.UsernameNotFoundException;
 import org.jboss.marshalling.reflect.SerializableClassRegistry;
+
 import static org.jenkinsci.plugins.workflow.cps.persistence.PersistenceContext.*;
 import org.jenkinsci.plugins.workflow.flow.FlowExecutionList;
 import org.kohsuke.accmod.restrictions.DoNotUse;
@@ -529,7 +530,7 @@ private void loadProgramFailed(final Throwable problem, SettableFuture<CpsThread
      *
      * <p>
      * If the {@link CpsThreadGroup} deserializatoin fails, {@link FutureCallback#onFailure(Throwable)} will
-     * be invoked (on a random thread, since {@link CpsVmThread} doesn't exist without a valid program.)
+     * be invoked (on a random thread, since CpsVmThread doesn't exist without a valid program.)
      */
     void runInCpsVmThread(final FutureCallback<CpsThreadGroup> callback) {
         if (programPromise == null) {
@@ -637,6 +638,31 @@ public void onFailure(Throwable t) {
         return r;
     }
 
+    /**
+     * Synchronously obtain the current state of the workflow program.
+     *
+     * <p>
+     * The workflow can be already completed, or it can still be running.
+     */
+    public CpsThreadDump getThreadDump() {
+        if (programPromise == null || isComplete()) {
+            return CpsThreadDump.EMPTY;
+        }
+        if (!programPromise.isDone()) {
+            // CpsThreadGroup state isn't ready yet, but this is probably one of the common cases
+            // when one wants to obtain the stack trace. Cf. JENKINS-26130.
+            return CpsThreadDump.UNKNOWN;
+        }
+
+        try {
+            return programPromise.get().getThreadDump();
+        } catch (InterruptedException e) {
+            throw new AssertionError(); // since we are checking programPromise.isDone() upfront
+        } catch (ExecutionException e) {
+            return CpsThreadDump.from(new Exception("Failed to resurrect program state",e));
+        }
+    }
+
     @Override
     public synchronized boolean isCurrentHead(FlowNode n) {
         for (FlowHead h : heads.values()) {

diff --git a/cps/src/main/java/org/jenkinsci/plugins/workflow/cps/CpsThread.java b/cps/src/main/java/org/jenkinsci/plugins/workflow/cps/CpsThread.java
@@ -259,6 +259,10 @@ public Future<Object> resume(Outcome v) {
         return promise;
     }
 
+    public List<StackTraceElement> getStackTrace() {
+        return program.getStackTrace();
+    }
+
     private static final Logger LOGGER = Logger.getLogger(CpsThread.class.getName());
 
     private static final long serialVersionUID = 1L;