add -debug flag to emit node output to files

.gitignore

@@ -3,4 +3,5 @@ TODO
 tmp/**/*
 *.coverprofile
 .vscode
-.idea/
+.idea/
+*.log

config/config.go

@@ -34,6 +34,7 @@ type GinkgoConfigType struct {
 	FlakeAttempts      int
 	EmitSpecProgress   bool
 	DryRun             bool
+	DebugParallel      bool
 
 	ParallelNode  int
 	ParallelTotal int
@@ -81,6 +82,8 @@ func Flags(flagSet *flag.FlagSet, prefix string, includeParallelFlags bool) {
 
 	flagSet.BoolVar(&(GinkgoConfig.EmitSpecProgress), prefix+"progress", false, "If set, ginkgo will emit progress information as each spec runs to the GinkgoWriter.")
 
+	flagSet.BoolVar(&(GinkgoConfig.DebugParallel), prefix+"debug", false, "If set, ginkgo will emit node output to files when running in parallel.")
+
 	if includeParallelFlags {
 		flagSet.IntVar(&(GinkgoConfig.ParallelNode), prefix+"parallel.node", 1, "This worker node's (one-indexed) node number.  For running specs in parallel.")
 		flagSet.IntVar(&(GinkgoConfig.ParallelTotal), prefix+"parallel.total", 1, "The total number of worker nodes.  For running specs in parallel.")
@@ -141,6 +144,10 @@ func BuildFlagArgs(prefix string, ginkgo GinkgoConfigType, reporter DefaultRepor
 		result = append(result, fmt.Sprintf("--%sprogress", prefix))
 	}
 
+	if ginkgo.DebugParallel {
+		result = append(result, fmt.Sprintf("--%sdebug", prefix))
+	}
+
 	if ginkgo.ParallelNode != 0 {
 		result = append(result, fmt.Sprintf("--%sparallel.node=%d", prefix, ginkgo.ParallelNode))
 	}

ginkgo/testrunner/test_runner.go

@@ -17,6 +17,7 @@ import (
 	"github.com/onsi/ginkgo/ginkgo/testsuite"
 	"github.com/onsi/ginkgo/internal/remote"
 	"github.com/onsi/ginkgo/reporters/stenographer"
+	colorable "github.com/onsi/ginkgo/reporters/stenographer/support/go-colorable"
 	"github.com/onsi/ginkgo/types"
 )
 
@@ -313,7 +314,7 @@ func (t *TestRunner) runParallelGinkgoSuite() RunResult {
 	writers := make([]*logWriter, t.numCPU)
 	reports := make([]*bytes.Buffer, t.numCPU)
 
-	stenographer := stenographer.New(!config.DefaultReporterConfig.NoColor, config.GinkgoConfig.FlakeAttempts > 1)
+	stenographer := stenographer.New(!config.DefaultReporterConfig.NoColor, config.GinkgoConfig.FlakeAttempts > 1, colorable.NewColorableStdout())
 	aggregator := remote.NewAggregator(t.numCPU, result, config.DefaultReporterConfig, stenographer)
 
 	server, err := remote.NewServer(t.numCPU)

ginkgo_dsl.go

@@ -29,6 +29,7 @@ import (
 	"github.com/onsi/ginkgo/internal/writer"
 	"github.com/onsi/ginkgo/reporters"
 	"github.com/onsi/ginkgo/reporters/stenographer"
+	colorable "github.com/onsi/ginkgo/reporters/stenographer/support/go-colorable"
 	"github.com/onsi/ginkgo/types"
 )
 
@@ -228,10 +229,14 @@ func RunSpecsWithCustomReporters(t GinkgoTestingT, description string, specRepor
 func buildDefaultReporter() Reporter {
 	remoteReportingServer := config.GinkgoConfig.StreamHost
 	if remoteReportingServer == "" {
-		stenographer := stenographer.New(!config.DefaultReporterConfig.NoColor, config.GinkgoConfig.FlakeAttempts > 1)
+		stenographer := stenographer.New(!config.DefaultReporterConfig.NoColor, config.GinkgoConfig.FlakeAttempts > 1, colorable.NewColorableStdout())
 		return reporters.NewDefaultReporter(config.DefaultReporterConfig, stenographer)
 	} else {
-		return remote.NewForwardingReporter(remoteReportingServer, &http.Client{}, remote.NewOutputInterceptor())
+		debugFile := ""
+		if config.GinkgoConfig.DebugParallel {
+			debugFile = fmt.Sprintf("ginkgo-node-%d.log", config.GinkgoConfig.ParallelNode)
+		}
+		return remote.NewForwardingReporter(config.DefaultReporterConfig, remoteReportingServer, &http.Client{}, remote.NewOutputInterceptor(), GinkgoWriter.(*writer.Writer), debugFile)
 	}
 }
 

integration/_fixtures/debug_parallel_fixture/debug_parallel_fixture_suite_test.go

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

integration/_fixtures/debug_parallel_fixture/debug_parallel_fixture_test.go

@@ -0,0 +1,18 @@
+package debug_parallel_fixture_test
+
+import (
+	"fmt"
+	"time"
+
+	. "github.com/onsi/ginkgo"
+)
+
+var _ = Describe("DebugParallelFixture", func() {
+	It("emits output to a file", func() {
+		for i := 0; i < 10; i += 1 {
+			fmt.Printf("StdOut %d\n", i)
+			GinkgoWriter.Write([]byte(fmt.Sprintf("GinkgoWriter %d\n", i)))
+		}
+		time.Sleep(time.Second)
+	})
+})

integration/integration_suite_test.go

@@ -93,4 +93,4 @@ func startGinkgo(dir string, args ...string) *gexec.Session {
 func removeSuccessfully(path string) {
 	err := os.RemoveAll(path)
 	Expect(err).NotTo(HaveOccurred())
-}
+}

integration/run_test.go

@@ -2,6 +2,7 @@ package integration_test
 
 import (
 	"fmt"
+	"io/ioutil"
 	"os"
 	"regexp"
 	"runtime"
@@ -292,6 +293,47 @@ var _ = Describe("Running Specs", func() {
 		})
 	})
 
+	Context("when running in parallel with -debug", func() {
+		BeforeEach(func() {
+			pathToTest = tmpPath("ginkgo")
+			copyIn("debug_parallel_fixture", pathToTest)
+		})
+
+		Context("without -v", func() {
+			It("should emit node output to files on disk", func() {
+				session := startGinkgo(pathToTest, "--nodes=2", "--debug")
+				Eventually(session).Should(gexec.Exit(0))
+
+				f0, err := ioutil.ReadFile(pathToTest + "/ginkgo-node-1.log")
+				Ω(err).ShouldNot(HaveOccurred())
+				f1, err := ioutil.ReadFile(pathToTest + "/ginkgo-node-2.log")
+				Ω(err).ShouldNot(HaveOccurred())
+				content := string(append(f0, f1...))
+
+				for i := 0; i < 10; i += 1 {
+					Ω(content).Should(ContainSubstring("StdOut %d\n", i))
+					Ω(content).Should(ContainSubstring("GinkgoWriter %d\n", i))
+				}
+			})
+		})
+
+		Context("without -v", func() {
+			It("should emit node output to files on disk, without duplicating the GinkgoWriter output", func() {
+				session := startGinkgo(pathToTest, "--nodes=2", "--debug", "-v")
+				Eventually(session).Should(gexec.Exit(0))
+
+				f0, err := ioutil.ReadFile(pathToTest + "/ginkgo-node-1.log")
+				Ω(err).ShouldNot(HaveOccurred())
+				f1, err := ioutil.ReadFile(pathToTest + "/ginkgo-node-2.log")
+				Ω(err).ShouldNot(HaveOccurred())
+				content := string(append(f0, f1...))
+
+				out := strings.Split(content, "GinkgoWriter 2")
+				Ω(out).Should(HaveLen(2))
+			})
+		})
+	})
+
 	Context("when streaming in parallel", func() {
 		BeforeEach(func() {
 			pathToTest = tmpPath("ginkgo")

internal/remote/fake_output_interceptor_test.go

@@ -1,5 +1,7 @@
 package remote_test
 
+import "os"
+
 type fakeOutputInterceptor struct {
 	DidStartInterceptingOutput bool
 	DidStopInterceptingOutput  bool
@@ -15,3 +17,6 @@ func (interceptor *fakeOutputInterceptor) StopInterceptingAndReturnOutput() (str
 	interceptor.DidStopInterceptingOutput = true
 	return interceptor.InterceptedOutput, nil
 }
+
+func (interceptor *fakeOutputInterceptor) StreamTo(*os.File) {
+}

internal/remote/forwarding_reporter.go

@@ -3,8 +3,14 @@ package remote
 import (
 	"bytes"
 	"encoding/json"
+	"fmt"
 	"io"
 	"net/http"
+	"os"
+
+	"github.com/onsi/ginkgo/internal/writer"
+	"github.com/onsi/ginkgo/reporters"
+	"github.com/onsi/ginkgo/reporters/stenographer"
 
 	"github.com/onsi/ginkgo/config"
 	"github.com/onsi/ginkgo/types"
@@ -30,14 +36,41 @@ type ForwardingReporter struct {
 	serverHost        string
 	poster            Poster
 	outputInterceptor OutputInterceptor
+	debugMode         bool
+	debugFile         *os.File
+	nestedReporter    *reporters.DefaultReporter
 }
 
-func NewForwardingReporter(serverHost string, poster Poster, outputInterceptor OutputInterceptor) *ForwardingReporter {
-	return &ForwardingReporter{
+func NewForwardingReporter(config config.DefaultReporterConfigType, serverHost string, poster Poster, outputInterceptor OutputInterceptor, ginkgoWriter *writer.Writer, debugFile string) *ForwardingReporter {
+	reporter := &ForwardingReporter{
 		serverHost:        serverHost,
 		poster:            poster,
 		outputInterceptor: outputInterceptor,
 	}
+
+	if debugFile != "" {
+		var err error
+		reporter.debugMode = true
+		reporter.debugFile, err = os.Create(debugFile)
+		if err != nil {
+			fmt.Println(err.Error())
+			os.Exit(1)
+		}
+
+		if !config.Verbose {
+			//if verbose is true then the GinkgoWriter emits to stdout.  Don't _also_ redirect GinkgoWriter output as that will result in duplication.
+			ginkgoWriter.AndRedirectTo(reporter.debugFile)
+		}
+		outputInterceptor.StreamTo(reporter.debugFile) //This is not working
+
+		stenographer := stenographer.New(false, true, reporter.debugFile)
+		config.Succinct = false
+		config.Verbose = true
+		config.FullTrace = true
+		reporter.nestedReporter = reporters.NewDefaultReporter(config, stenographer)
+	}
+
+	return reporter
 }
 
 func (reporter *ForwardingReporter) post(path string, data interface{}) {
@@ -56,35 +89,59 @@ func (reporter *ForwardingReporter) SpecSuiteWillBegin(conf config.GinkgoConfigT
 	}
 
 	reporter.outputInterceptor.StartInterceptingOutput()
+	if reporter.debugMode {
+		reporter.nestedReporter.SpecSuiteWillBegin(conf, summary)
+		reporter.debugFile.Sync()
+	}
 	reporter.post("/SpecSuiteWillBegin", data)
 }
 
 func (reporter *ForwardingReporter) BeforeSuiteDidRun(setupSummary *types.SetupSummary) {
 	output, _ := reporter.outputInterceptor.StopInterceptingAndReturnOutput()
 	reporter.outputInterceptor.StartInterceptingOutput()
 	setupSummary.CapturedOutput = output
+	if reporter.debugMode {
+		reporter.nestedReporter.BeforeSuiteDidRun(setupSummary)
+		reporter.debugFile.Sync()
+	}
 	reporter.post("/BeforeSuiteDidRun", setupSummary)
 }
 
 func (reporter *ForwardingReporter) SpecWillRun(specSummary *types.SpecSummary) {
+	if reporter.debugMode {
+		reporter.nestedReporter.SpecWillRun(specSummary)
+		reporter.debugFile.Sync()
+	}
 	reporter.post("/SpecWillRun", specSummary)
 }
 
 func (reporter *ForwardingReporter) SpecDidComplete(specSummary *types.SpecSummary) {
 	output, _ := reporter.outputInterceptor.StopInterceptingAndReturnOutput()
 	reporter.outputInterceptor.StartInterceptingOutput()
 	specSummary.CapturedOutput = output
+	if reporter.debugMode {
+		reporter.nestedReporter.SpecDidComplete(specSummary)
+		reporter.debugFile.Sync()
+	}
 	reporter.post("/SpecDidComplete", specSummary)
 }
 
 func (reporter *ForwardingReporter) AfterSuiteDidRun(setupSummary *types.SetupSummary) {
 	output, _ := reporter.outputInterceptor.StopInterceptingAndReturnOutput()
 	reporter.outputInterceptor.StartInterceptingOutput()
 	setupSummary.CapturedOutput = output
+	if reporter.debugMode {
+		reporter.nestedReporter.AfterSuiteDidRun(setupSummary)
+		reporter.debugFile.Sync()
+	}
 	reporter.post("/AfterSuiteDidRun", setupSummary)
 }
 
 func (reporter *ForwardingReporter) SpecSuiteDidEnd(summary *types.SuiteSummary) {
 	reporter.outputInterceptor.StopInterceptingAndReturnOutput()
+	if reporter.debugMode {
+		reporter.nestedReporter.SpecSuiteDidEnd(summary)
+		reporter.debugFile.Sync()
+	}
 	reporter.post("/SpecSuiteDidEnd", summary)
 }

internal/remote/forwarding_reporter_test.go

@@ -30,7 +30,7 @@ var _ = Describe("ForwardingReporter", func() {
 			InterceptedOutput: "The intercepted output!",
 		}
 
-		reporter = NewForwardingReporter(serverHost, poster, interceptor)
+		reporter = NewForwardingReporter(config.DefaultReporterConfigType{}, serverHost, poster, interceptor, nil, "")
 
 		suiteSummary = &types.SuiteSummary{
 			SuiteDescription: "My Test Suite",

internal/remote/output_interceptor.go

@@ -1,10 +1,13 @@
 package remote
 
+import "os"
+
 /*
 The OutputInterceptor is used by the ForwardingReporter to
 intercept and capture all stdin and stderr output during a test run.
 */
 type OutputInterceptor interface {
 	StartInterceptingOutput() error
 	StopInterceptingAndReturnOutput() (string, error)
+	StreamTo(*os.File)
 }

internal/remote/output_interceptor_unix.go

@@ -6,6 +6,8 @@ import (
 	"errors"
 	"io/ioutil"
 	"os"
+
+	"github.com/hpcloud/tail"
 )
 
 func NewOutputInterceptor() OutputInterceptor {
@@ -14,7 +16,10 @@ func NewOutputInterceptor() OutputInterceptor {
 
 type outputInterceptor struct {
 	redirectFile *os.File
+	streamTarget *os.File
 	intercepting bool
+	tailer       *tail.Tail
+	doneTailing  chan bool
 }
 
 func (interceptor *outputInterceptor) StartInterceptingOutput() error {
@@ -37,6 +42,18 @@ func (interceptor *outputInterceptor) StartInterceptingOutput() error {
 	syscallDup(int(interceptor.redirectFile.Fd()), 1)
 	syscallDup(int(interceptor.redirectFile.Fd()), 2)
 
+	if interceptor.streamTarget != nil {
+		interceptor.tailer, _ = tail.TailFile(interceptor.redirectFile.Name(), tail.Config{Follow: true})
+		interceptor.doneTailing = make(chan bool)
+
+		go func() {
+			for line := range interceptor.tailer.Lines {
+				interceptor.streamTarget.Write([]byte(line.Text + "\n"))
+			}
+			close(interceptor.doneTailing)
+		}()
+	}
+
 	return nil
 }
 
@@ -51,5 +68,16 @@ func (interceptor *outputInterceptor) StopInterceptingAndReturnOutput() (string,
 
 	interceptor.intercepting = false
 
+	if interceptor.streamTarget != nil {
+		interceptor.tailer.Stop()
+		interceptor.tailer.Cleanup()
+		<-interceptor.doneTailing
+		interceptor.streamTarget.Sync()
+	}
+
 	return string(output), err
 }
+
+func (interceptor *outputInterceptor) StreamTo(out *os.File) {
+	interceptor.streamTarget = out
+}