Add -showDebugAddress to enable debugging hanging parallel tests

CHANGELOG.md

@@ -1,5 +1,8 @@
 ## HEAD
 
+- Running parallel tests with `-showDebugAddress` now prints out a Debug URL when the test begins.  http GETting from this URL returns a JSON payload that describes the currently running spec for each parallel node.  This payload will include any output the spec has emitted (either to stdout or the GinkgoWriter).
+
+The intent behind `-showDebugAddress` is to enable users to debug parallel test suites that are hanging.  We recommend enabling `-showDebugAddress` in your CI setup.
 - When using custom reporters register the custom reporters *before* the default reporter.  This allows users to see the output of any print statements in their customer reporters. [#365]
 - When running a test and calculating the coverage using the `-coverprofile` and `-outputdir` flags, Ginkgo fails with an error if the directory does not exist. This is due to an [issue in go 1.10](https://github.com/golang/go/issues/24588) [#446]
 

ginkgo/build_command.go

@@ -46,7 +46,7 @@ func (r *SpecBuilder) BuildSpecs(args []string, additionalArgs []string) {
 
 	passed := true
 	for _, suite := range suites {
-		runner := testrunner.New(suite, 1, false, 0, r.commandFlags.GoOpts, nil)
+		runner := testrunner.New(suite, 1, false, false, 0, r.commandFlags.GoOpts, nil)
 		fmt.Printf("Compiling %s...\n", suite.PackageName)
 
 		path, _ := filepath.Abs(filepath.Join(suite.Path, fmt.Sprintf("%s.test", suite.PackageName)))

ginkgo/run_command.go

@@ -75,7 +75,7 @@ func (r *SpecRunner) RunSpecs(args []string, additionalArgs []string) {
 
 	runners := []*testrunner.TestRunner{}
 	for _, suite := range suites {
-		runners = append(runners, testrunner.New(suite, r.commandFlags.NumCPU, r.commandFlags.ParallelStream, r.commandFlags.Timeout, r.commandFlags.GoOpts, additionalArgs))
+		runners = append(runners, testrunner.New(suite, r.commandFlags.NumCPU, r.commandFlags.ParallelStream, r.commandFlags.ShowParallelDebugAddress, r.commandFlags.Timeout, r.commandFlags.GoOpts, additionalArgs))
 	}
 
 	numSuites := 0

ginkgo/run_watch_and_build_command_flags.go

@@ -15,13 +15,14 @@ type RunWatchAndBuildCommandFlags struct {
 	GoOpts      map[string]interface{}
 
 	//for run and watch commands
-	NumCPU         int
-	NumCompilers   int
-	ParallelStream bool
-	Notify         bool
-	AfterSuiteHook string
-	AutoNodes      bool
-	Timeout        time.Duration
+	NumCPU                   int
+	NumCompilers             int
+	ParallelStream           bool
+	ShowParallelDebugAddress bool
+	Notify                   bool
+	AfterSuiteHook           string
+	AutoNodes                bool
+	Timeout                  time.Duration
 
 	//only for run command
 	KeepGoing       bool
@@ -147,6 +148,7 @@ func (c *RunWatchAndBuildCommandFlags) flags(mode int) {
 		c.FlagSet.IntVar(&(c.NumCompilers), "compilers", 0, "The number of concurrent compilations to run (0 will autodetect)")
 		c.FlagSet.BoolVar(&(c.AutoNodes), "p", false, "Run in parallel with auto-detected number of nodes")
 		c.FlagSet.BoolVar(&(c.ParallelStream), "stream", onWindows, "stream parallel test output in real time: less coherent, but useful for debugging")
+		c.FlagSet.BoolVar(&(c.ShowParallelDebugAddress), "showDebugAddress", false, "show parallel test debug address")
 		if !onWindows {
 			c.FlagSet.BoolVar(&(c.Notify), "notify", false, "Send desktop notifications when a test run completes")
 		}

ginkgo/testrunner/test_runner.go

@@ -26,25 +26,27 @@ type TestRunner struct {
 	compiled              bool
 	compilationTargetPath string
 
-	numCPU         int
-	parallelStream bool
-	timeout        time.Duration
-	goOpts         map[string]interface{}
-	additionalArgs []string
-	stderr         *bytes.Buffer
+	numCPU           int
+	parallelStream   bool
+	timeout          time.Duration
+	goOpts           map[string]interface{}
+	additionalArgs   []string
+	stderr           *bytes.Buffer
+	showDebugAddress bool
 
 	CoverageFile string
 }
 
-func New(suite testsuite.TestSuite, numCPU int, parallelStream bool, timeout time.Duration, goOpts map[string]interface{}, additionalArgs []string) *TestRunner {
+func New(suite testsuite.TestSuite, numCPU int, parallelStream bool, showDebugAddress bool, timeout time.Duration, goOpts map[string]interface{}, additionalArgs []string) *TestRunner {
 	runner := &TestRunner{
-		Suite:          suite,
-		numCPU:         numCPU,
-		parallelStream: parallelStream,
-		goOpts:         goOpts,
-		additionalArgs: additionalArgs,
-		timeout:        timeout,
-		stderr:         new(bytes.Buffer),
+		Suite:            suite,
+		numCPU:           numCPU,
+		parallelStream:   parallelStream,
+		showDebugAddress: showDebugAddress,
+		goOpts:           goOpts,
+		additionalArgs:   additionalArgs,
+		timeout:          timeout,
+		stderr:           new(bytes.Buffer),
 	}
 
 	if !suite.Precompiled {
@@ -259,7 +261,7 @@ func (t *TestRunner) runAndStreamParallelGinkgoSuite() RunResult {
 	completions := make(chan RunResult)
 	writers := make([]*logWriter, t.numCPU)
 
-	server, err := remote.NewServer(t.numCPU)
+	server, err := remote.NewServer(t.numCPU, nil)
 	if err != nil {
 		panic("Failed to start parallel spec server")
 	}
@@ -308,19 +310,23 @@ func (t *TestRunner) runAndStreamParallelGinkgoSuite() RunResult {
 }
 
 func (t *TestRunner) runParallelGinkgoSuite() RunResult {
-	result := make(chan bool)
+	result := make(chan bool, 1)
 	completions := make(chan RunResult)
 	writers := make([]*logWriter, t.numCPU)
 	reports := make([]*bytes.Buffer, t.numCPU)
 
 	stenographer := stenographer.New(!config.DefaultReporterConfig.NoColor, config.GinkgoConfig.FlakeAttempts > 1)
 	aggregator := remote.NewAggregator(t.numCPU, result, config.DefaultReporterConfig, stenographer)
 
-	server, err := remote.NewServer(t.numCPU)
+	server, err := remote.NewServer(t.numCPU, aggregator)
 	if err != nil {
 		panic("Failed to start parallel spec server")
 	}
-	server.RegisterReporters(aggregator)
+
+	if t.showDebugAddress {
+		fmt.Println(t.Suite.PackageName, "Debug URL: ", server.Address()+"/debug")
+	}
+
 	server.Start()
 	defer server.Close()
 
@@ -344,6 +350,13 @@ func (t *TestRunner) runParallelGinkgoSuite() RunResult {
 			return !cmd.ProcessState.Exited()
 		})
 
+		server.RegisterSignalDebug(cpu+1, func() {
+			if cmd.Process == nil {
+				return
+			}
+			cmd.Process.Signal(syscall.SIGUSR1)
+		})
+
 		go t.run(cmd, completions)
 	}
 

ginkgo/testrunner/test_runner_test.go

@@ -33,7 +33,7 @@ var _ = Describe("TestRunner", func() {
 			"cover":            boolAddr(false),
 			"blockprofilerate": intAddr(100),
 		}
-		tr := testrunner.New(testsuite.TestSuite{}, 1, false, 0, opts, []string{})
+		tr := testrunner.New(testsuite.TestSuite{}, 1, false, false, 0, opts, []string{})
 
 		args := tr.BuildArgs(".")
 		Ω(args).Should(Equal([]string{

ginkgo/watch_command.go

@@ -59,7 +59,7 @@ func (w *SpecWatcher) runnersForSuites(suites []testsuite.TestSuite, additionalA
 	runners := []*testrunner.TestRunner{}
 
 	for _, suite := range suites {
-		runners = append(runners, testrunner.New(suite, w.commandFlags.NumCPU, w.commandFlags.ParallelStream, w.commandFlags.Timeout, w.commandFlags.GoOpts, additionalArgs))
+		runners = append(runners, testrunner.New(suite, w.commandFlags.NumCPU, w.commandFlags.ParallelStream, w.commandFlags.ShowParallelDebugAddress, w.commandFlags.Timeout, w.commandFlags.GoOpts, additionalArgs))
 	}
 
 	return runners

ginkgo_dsl.go

@@ -231,7 +231,7 @@ func buildDefaultReporter() Reporter {
 		stenographer := stenographer.New(!config.DefaultReporterConfig.NoColor, config.GinkgoConfig.FlakeAttempts > 1)
 		return reporters.NewDefaultReporter(config.DefaultReporterConfig, stenographer)
 	} else {
-		return remote.NewForwardingReporter(remoteReportingServer, &http.Client{}, remote.NewOutputInterceptor())
+		return remote.NewForwardingReporter(remoteReportingServer, &http.Client{}, remote.NewOutputInterceptor(), config.GinkgoConfig.ParallelNode, GinkgoWriter.(*writer.Writer))
 	}
 }
 

integration/_fixtures/slow_parallel_test/slow_parallel_suite_test.go

@@ -0,0 +1,13 @@
+package slow_parallel_suite_test
+
+import (
+	. "github.com/onsi/ginkgo"
+	. "github.com/onsi/gomega"
+
+	"testing"
+)
+
+func TestHangingSuite(t *testing.T) {
+	RegisterFailHandler(Fail)
+	RunSpecs(t, "SlowParallelSuite Suite")
+}

integration/_fixtures/slow_parallel_test/slow_parallel_test.go

@@ -0,0 +1,16 @@
+package slow_parallel_suite_test
+
+import (
+	"fmt"
+	"time"
+
+	. "github.com/onsi/ginkgo"
+)
+
+var _ = Describe("SlowParallelSuite", func() {
+	It("should hang out for a while", func() {
+		fmt.Fprintln(GinkgoWriter, "Slow Test is Hanging Out")
+		fmt.Println("Slow Test is Sleeping...")
+		time.Sleep(5 * time.Second)
+	})
+})

integration/run_test.go

@@ -2,6 +2,8 @@ package integration_test
 
 import (
 	"fmt"
+	"io/ioutil"
+	"net/http"
 	"os"
 	"regexp"
 	"runtime"
@@ -257,12 +259,12 @@ var _ = Describe("Running Specs", func() {
 	})
 
 	Context("when running in parallel", func() {
-		BeforeEach(func() {
-			pathToTest = tmpPath("ginkgo")
-			copyIn("passing_ginkgo_tests", pathToTest)
-		})
-
 		Context("with a specific number of -nodes", func() {
+			BeforeEach(func() {
+				pathToTest = tmpPath("ginkgo")
+				copyIn("passing_ginkgo_tests", pathToTest)
+			})
+
 			It("should use the specified number of nodes", func() {
 				session := startGinkgo(pathToTest, "--noColor", "-succinct", "-nodes=2")
 				Eventually(session).Should(gexec.Exit(0))
@@ -274,6 +276,11 @@ var _ = Describe("Running Specs", func() {
 		})
 
 		Context("with -p", func() {
+			BeforeEach(func() {
+				pathToTest = tmpPath("ginkgo")
+				copyIn("passing_ginkgo_tests", pathToTest)
+			})
+
 			It("it should autocompute the number of nodes", func() {
 				session := startGinkgo(pathToTest, "--noColor", "-succinct", "-p")
 				Eventually(session).Should(gexec.Exit(0))
@@ -290,6 +297,34 @@ var _ = Describe("Running Specs", func() {
 				Ω(output).Should(ContainSubstring("Test Suite Passed"))
 			})
 		})
+
+		Context("with -showDebugAddress", func() {
+			BeforeEach(func() {
+				pathToTest = tmpPath("slow")
+				copyIn("slow_parallel_test", pathToTest)
+			})
+
+			It("enables the user to debug the suite", func() {
+				session := startGinkgo(pathToTest, "--noColor", "-nodes=2", "-showDebugAddress")
+				Eventually(session).Should(gbytes.Say("Debug URL:"))
+				re := regexp.MustCompile(`Debug URL:\s+(http://127.0.0.1:\d*/debug)`)
+				url := re.FindStringSubmatch(string(session.Out.Contents()))[1]
+
+				getDebugInfo := func() string {
+					resp, err := http.Get(url)
+					Ω(err).ShouldNot(HaveOccurred())
+					content, err := ioutil.ReadAll(resp.Body)
+					Ω(err).ShouldNot(HaveOccurred())
+					resp.Body.Close()
+					return string(content)
+				}
+
+				Eventually(getDebugInfo).Should(ContainSubstring("Slow Test is Hanging Out"), "Debug endpoint captures GinkgoWriter output while the test is running")
+				Eventually(getDebugInfo).Should(ContainSubstring("Slow Test is Sleeping..."), "Debug endpoint captures output while the test is running")
+
+				Eventually(session).Should(gexec.Exit(0))
+			})
+		})
 	})
 
 	Context("when streaming in parallel", func() {