Repository: gotestyourself/gotestsum
Pull request #306 (2023-02-16 17:22:53)

Add jsonfile-timing-events flag for capturing only the timing events in a file
Branched from #305

Adds a new `--jsonfile-timing-events` flag. Similar to `--jsonfile`, all of the pass, fail, and skip events are written to this file.

This is useful when `gotestsum` is used with large projects that emit lots of verbose logs from tests. This new flag removes the need to post-process the jsonfile before saving it to an artifact.

See https://github.com/gotestyourself/gotestsum/issues/303#issuecomment-1423179939 and https://github.com/gotestyourself/gotestsum/pull/258#issuecomment-1236373878


Patch:
diff --git a/cmd/handler.go b/cmd/handler.go
index 8bb0bbd..8c47205 100644
--- a/cmd/handler.go
+++ b/cmd/handler.go
@@ -1,6 +1,7 @@
 package cmd
 
 import (
+	"bufio"
 	"fmt"
 	"io"
 	"os"
@@ -13,10 +14,11 @@ import (
 )
 
 type eventHandler struct {
-	formatter testjson.EventFormatter
-	err       io.Writer
-	jsonFile  writeSyncer
-	maxFails  int
+	formatter            testjson.EventFormatter
+	err                  *bufio.Writer
+	jsonFile             writeSyncer
+	jsonFileTimingEvents writeSyncer
+	maxFails             int
 }
 
 type writeSyncer interface {
@@ -24,17 +26,21 @@ type writeSyncer interface {
 	Sync() error
 }
 
+// nolint:errcheck
 func (h *eventHandler) Err(text string) error {
-	_, _ = h.err.Write([]byte(text + "\n"))
+	h.err.WriteString(text)
+	h.err.WriteRune('\n')
+	h.err.Flush()
 	// always return nil, no need to stop scanning if the stderr write fails
 	return nil
 }
 
 func (h *eventHandler) Event(event testjson.TestEvent, execution *testjson.Execution) error {
-	// ignore artificial events with no raw Bytes()
-	if h.jsonFile != nil && len(event.Bytes()) > 0 {
-		_, err := h.jsonFile.Write(append(event.Bytes(), '\n'))
-		if err != nil {
+	if err := writeWithNewline(h.jsonFile, event.Bytes()); err != nil {
+		return fmt.Errorf("failed to write JSON file: %w", err)
+	}
+	if event.Action.IsTerminal() {
+		if err := writeWithNewline(h.jsonFileTimingEvents, event.Bytes()); err != nil {
 			return fmt.Errorf("failed to write JSON file: %w", err)
 		}
 	}
@@ -50,12 +56,29 @@ func (h *eventHandler) Event(event testjson.TestEvent, execution *testjson.Execu
 	return nil
 }
 
+func writeWithNewline(out io.Writer, b []byte) error {
+	// ignore artificial events that have len(b) == 0
+	if out == nil || len(b) == 0 {
+		return nil
+	}
+	if _, err := out.Write(b); err != nil {
+		return err
+	}
+	_, err := out.Write([]byte{'\n'})
+	return err
+}
+
 func (h *eventHandler) Flush() {
 	if h.jsonFile != nil {
 		if err := h.jsonFile.Sync(); err != nil {
 			log.Errorf("Failed to sync JSON file: %v", err)
 		}
 	}
+	if h.jsonFileTimingEvents != nil {
+		if err := h.jsonFileTimingEvents.Sync(); err != nil {
+			log.Errorf("Failed to sync JSON file: %v", err)
+		}
+	}
 }
 
 func (h *eventHandler) Close() error {
@@ -64,6 +87,11 @@ func (h *eventHandler) Close() error {
 			log.Errorf("Failed to close JSON file: %v", err)
 		}
 	}
+	if h.jsonFileTimingEvents != nil {
+		if err := h.jsonFileTimingEvents.Close(); err != nil {
+			log.Errorf("Failed to close JSON file: %v", err)
+		}
+	}
 	return nil
 }
 
@@ -76,7 +104,7 @@ func newEventHandler(opts *options) (*eventHandler, error) {
 	}
 	handler := &eventHandler{
 		formatter: formatter,
-		err:       opts.stderr,
+		err:       bufio.NewWriter(opts.stderr),
 		maxFails:  opts.maxFails,
 	}
 	var err error
@@ -84,7 +112,14 @@ func newEventHandler(opts *options) (*eventHandler, error) {
 		_ = os.MkdirAll(filepath.Dir(opts.jsonFile), 0o755)
 		handler.jsonFile, err = os.Create(opts.jsonFile)
 		if err != nil {
-			return handler, fmt.Errorf("failed to open JSON file: %w", err)
+			return handler, fmt.Errorf("failed to create file: %w", err)
+		}
+	}
+	if opts.jsonFileTimingEvents != "" {
+		_ = os.MkdirAll(filepath.Dir(opts.jsonFileTimingEvents), 0o755)
+		handler.jsonFileTimingEvents, err = os.Create(opts.jsonFileTimingEvents)
+		if err != nil {
+			return handler, fmt.Errorf("failed to create file: %w", err)
 		}
 	}
 	return handler, nil
@@ -125,6 +160,7 @@ func postRunHook(opts *options, execution *testjson.Execution) error {
 	cmd.Env = append(
 		os.Environ(),
 		"GOTESTSUM_JSONFILE="+opts.jsonFile,
+		"GOTESTSUM_JSONFILE_TIMING_EVENTS="+opts.jsonFileTimingEvents,
 		"GOTESTSUM_JUNITFILE="+opts.junitFile,
 		fmt.Sprintf("TESTS_TOTAL=%d", execution.Total()),
 		fmt.Sprintf("TESTS_FAILED=%d", len(execution.Failed())),
diff --git a/cmd/main.go b/cmd/main.go
index d6c4b81..732b99b 100644
--- a/cmd/main.go
+++ b/cmd/main.go
@@ -71,6 +71,9 @@ func setupFlags(name string) (*pflag.FlagSet, *options) {
 	flags.StringVar(&opts.jsonFile, "jsonfile",
 		lookEnvWithDefault("GOTESTSUM_JSONFILE", ""),
 		"write all TestEvents to file")
+	flags.StringVar(&opts.jsonFileTimingEvents, "jsonfile-timing-events",
+		lookEnvWithDefault("GOTESTSUM_JSONFILE_TIMING_EVENTS", ""),
+		"write only the pass, skip, and fail TestEvents to the file")
 	flags.BoolVar(&opts.noColor, "no-color", defaultNoColor, "disable color output")
 
 	flags.Var(opts.hideSummary, "no-summary",
@@ -160,6 +163,7 @@ type options struct {
 	rawCommand                   bool
 	ignoreNonJSONOutputLines     bool
 	jsonFile                     string
+	jsonFileTimingEvents         string
 	junitFile                    string
 	postRunHookCmd               *commandValue
 	noColor                      bool


Test patch:
diff --git a/cmd/handler_test.go b/cmd/handler_test.go
index 4547fb7..48322de 100644
--- a/cmd/handler_test.go
+++ b/cmd/handler_test.go
@@ -22,10 +22,11 @@ func TestPostRunHook(t *testing.T) {
 
 	buf := new(bytes.Buffer)
 	opts := &options{
-		postRunHookCmd: command,
-		jsonFile:       "events.json",
-		junitFile:      "junit.xml",
-		stdout:         buf,
+		postRunHookCmd:       command,
+		jsonFile:             "events.json",
+		jsonFileTimingEvents: "timing.json",
+		junitFile:            "junit.xml",
+		stdout:               buf,
 	}
 
 	env.Patch(t, "GOTESTSUM_FORMAT", "short")
diff --git a/cmd/main_test.go b/cmd/main_test.go
index 67c8b8e..526f2ce 100644
--- a/cmd/main_test.go
+++ b/cmd/main_test.go
@@ -486,3 +486,37 @@ func TestRun_JsonFileIsSyncedBeforePostRunCommand(t *testing.T) {
 	_, actual, _ := strings.Cut(out.String(), "s\n") // remove the DONE line
 	assert.Equal(t, actual, expected)
 }
+
+func TestRun_JsonFileTimingEvents(t *testing.T) {
+	input := golden.Get(t, "../../testjson/testdata/input/go-test-json.out")
+
+	fn := func(args []string) *proc {
+		return &proc{
+			cmd:    fakeWaiter{},
+			stdout: bytes.NewReader(input),
+			stderr: bytes.NewReader(nil),
+		}
+	}
+	reset := patchStartGoTestFn(fn)
+	defer reset()
+
+	tmp := t.TempDir()
+	jsonFileTiming := filepath.Join(tmp, "json.log")
+
+	out := new(bytes.Buffer)
+	opts := &options{
+		rawCommand:           true,
+		args:                 []string{"./test.test"},
+		format:               "none",
+		stdout:               out,
+		stderr:               os.Stderr,
+		hideSummary:          &hideSummaryValue{value: testjson.SummarizeNone},
+		jsonFileTimingEvents: jsonFileTiming,
+	}
+	err := run(opts)
+	assert.NilError(t, err)
+
+	raw, err := os.ReadFile(jsonFileTiming)
+	assert.NilError(t, err)
+	golden.Assert(t, string(raw), "expected-jsonfile-timing-events")
+}
diff --git a/cmd/testdata/expected-jsonfile-timing-events b/cmd/testdata/expected-jsonfile-timing-events
new file mode 100644
index 0000000..b9031a1
--- /dev/null
+++ b/cmd/testdata/expected-jsonfile-timing-events
@@ -0,0 +1,64 @@
+{"Time":"2022-06-19T13:44:44.851087257-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/badmain","Elapsed":0.001}
+{"Time":"2022-06-19T13:44:44.855151131-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/empty","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859699224-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestPassed","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859712195-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestPassedWithLog","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859724262-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestPassedWithStdout","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859741082-04:00","Action":"skip","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestSkipped","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859753158-04:00","Action":"skip","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestSkippedWitLog","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859765298-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestWithStderr","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859850991-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/a/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859853265-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/a","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859862788-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/b/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.85986508-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/b","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859872517-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/c/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859874632-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/c","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859881961-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/d/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859884191-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess/d","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859886372-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestNestedSuccess","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859895611-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestParallelTheFirst","Elapsed":0.01}
+{"Time":"2022-06-19T13:44:44.859913525-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestParallelTheThird","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.859918336-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Test":"TestParallelTheSecond","Elapsed":0.01}
+{"Time":"2022-06-19T13:44:44.859926497-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/good","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914336528-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestPassed","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914351368-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestPassedWithLog","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914364274-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestPassedWithStdout","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914382623-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestWithStderr","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914503606-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestNestedParallelFailures/a","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914508601-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestNestedParallelFailures/d","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914513457-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestNestedParallelFailures/c","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914518402-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestNestedParallelFailures/b","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.914520636-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestNestedParallelFailures","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.924699091-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestParallelTheFirst","Elapsed":0.01}
+{"Time":"2022-06-19T13:44:44.926895283-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestParallelTheThird","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.933108555-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Test":"TestParallelTheSecond","Elapsed":0.01}
+{"Time":"2022-06-19T13:44:44.933277617-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/parallelfails","Elapsed":0.02}
+{"Time":"2022-06-19T13:44:44.988321998-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestPassed","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988339579-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestPassedWithLog","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988360671-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestPassedWithStdout","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988373636-04:00","Action":"skip","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestSkipped","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988385879-04:00","Action":"skip","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestSkippedWitLog","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988400233-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestFailed","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988412375-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestWithStderr","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988429392-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestFailedWithStderr","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988523195-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/a/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988525729-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/a","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988533344-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/b/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988535616-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/b","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988540575-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/c","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.98855307-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/d/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988555926-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure/d","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988558303-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedWithFailure","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988613572-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/a/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.98861593-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/a","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988623564-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/b/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988625803-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/b","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.98863313-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/c/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988635513-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/c","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988643545-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/d/sub","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988645759-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess/d","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988647935-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestNestedSuccess","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.988663887-04:00","Action":"skip","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestTimeout","Elapsed":0}
+{"Time":"2022-06-19T13:44:44.998850256-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestParallelTheFirst","Elapsed":0.01}
+{"Time":"2022-06-19T13:44:45.000983481-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestParallelTheThird","Elapsed":0}
+{"Time":"2022-06-19T13:44:45.007374647-04:00","Action":"pass","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Test":"TestParallelTheSecond","Elapsed":0.01}
+{"Time":"2022-06-19T13:44:45.00795073-04:00","Action":"fail","Package":"gotest.tools/gotestsum/testjson/internal/withfails","Elapsed":0.02}
diff --git a/cmd/testdata/gotestsum-help-text b/cmd/testdata/gotestsum-help-text
index 2092808..5fbbc8c 100644
--- a/cmd/testdata/gotestsum-help-text
+++ b/cmd/testdata/gotestsum-help-text
@@ -11,6 +11,7 @@ Flags:
       --format-hivis                                use high visibility characters in some formats
       --hide-summary summary                        hide sections of the summary: skipped,failed,errors,output (default none)
       --jsonfile string                             write all TestEvents to file
+      --jsonfile-timing-events string               write only the pass, skip, and fail TestEvents to the file
       --junitfile string                            write a JUnit XML file
       --junitfile-hide-empty-pkg                    omit packages with no tests from the junit.xml file
       --junitfile-project-name string               name of the project used in the junit.xml file
diff --git a/cmd/testdata/post-run-hook-expected b/cmd/testdata/post-run-hook-expected
index 8826f12..5c1ebcf 100644
--- a/cmd/testdata/post-run-hook-expected
+++ b/cmd/testdata/post-run-hook-expected
@@ -1,5 +1,6 @@
 GOTESTSUM_FORMAT=short
 GOTESTSUM_JSONFILE=events.json
+GOTESTSUM_JSONFILE_TIMING_EVENTS=timing.json
 GOTESTSUM_JUNITFILE=junit.xml
 TESTS_ERRORS=0
 TESTS_FAILED=13