feat: Parallel tests with global logger (google#1798)

Proof of concept of Parallel testing with a global logger via black
magic (inspecting stack traces).

Changes in this PR:
- Refactor `cmdlogger.CmdLogger` to be an interface.
- Move `cmdlogger.CmdLogger` implementation to be `cmdlogger.Handler`
- Create a new logging package caled `testlogger`, and an implementation
of `cmdlogger.CmdLogger` called `testlogger.Handler`
- `testlogger.Handler` passes all logging queries to a map of underlying
`cmdlogger.CmdLogger`s, with the key being the memory address value of
`testing.T` passed into each test.
- I believe this address should be unique for the lifespan of each test,
even if after the test the same memory address gets reused.
- Move static function into `static.go`

This results in much faster test runtimes again. On my local machine, it
takes the time taken down from over 5 minutes to <30 seconds.

Obviously this is not the most stable approach, as internal function
names and variables can change any time go is updated, but since this is
only used in tests, and breakages would be quite loud, I believe this is
acceptable.

Author: another-rex

cmd/osv-reporter/main.go

@@ -37,7 +37,7 @@ func splitLastArg(args []string) []string {
 func run(args []string, stdout, stderr io.Writer) int {
 	logger := cmdlogger.New(stdout, stderr)
 
-	slog.SetDefault(slog.New(&logger))
+	slog.SetDefault(slog.New(logger))
 
 	// Allow multiple arguments to be defined by github actions by splitting the last argument
 	// by new lines.

cmd/osv-scanner/fix/command_test.go

@@ -22,6 +22,8 @@ func matchFile(t *testing.T, file string) {
 }
 
 func TestCommand(t *testing.T) {
+	t.Parallel()
+
 	tests := []struct {
 		name     string
 		args     []string
@@ -68,6 +70,8 @@ func TestCommand(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
+			t.Parallel()
+
 			tc := testcmd.Case{
 				Name: tt.name,
 				Args: slices.Clone(tt.args),

cmd/osv-scanner/fix/testmain_test.go

@@ -1,12 +1,15 @@
 package fix
 
 import (
+	"log/slog"
 	"testing"
 
+	"github.com/google/osv-scanner/v2/internal/testlogger"
 	"github.com/google/osv-scanner/v2/internal/testutility"
 )
 
 func TestMain(m *testing.M) {
+	slog.SetDefault(slog.New(testlogger.New()))
 	m.Run()
 
 	testutility.CleanSnapshots(m)

cmd/osv-scanner/internal/cmd/helpers_test.go

@@ -69,7 +69,7 @@ func Test_insertDefaultCommand(t *testing.T) {
 
 		logger := cmdlogger.New(stdout, stderr)
 
-		slog.SetDefault(slog.New(&logger))
+		slog.SetDefault(slog.New(logger))
 
 		argsActual := insertDefaultCommand(tt.originalArgs, commands, defaultCommand, stderr)
 		if !reflect.DeepEqual(argsActual, tt.wantArgs) {

cmd/osv-scanner/internal/cmd/run.go

@@ -5,11 +5,13 @@ import (
 	"fmt"
 	"io"
 	"log/slog"
+	"testing"
 
 	"github.com/google/osv-scanner/v2/cmd/osv-scanner/fix"
 	"github.com/google/osv-scanner/v2/cmd/osv-scanner/scan"
 	"github.com/google/osv-scanner/v2/cmd/osv-scanner/update"
 	"github.com/google/osv-scanner/v2/internal/cmdlogger"
+	"github.com/google/osv-scanner/v2/internal/testlogger"
 	"github.com/google/osv-scanner/v2/internal/version"
 	"github.com/google/osv-scanner/v2/pkg/osvscanner"
 	"github.com/urfave/cli/v2"
@@ -21,9 +23,23 @@ var (
 )
 
 func Run(args []string, stdout, stderr io.Writer) int {
-	logger := cmdlogger.New(stdout, stderr)
+	// --- Setup Logger ---
+	logHandler := cmdlogger.New(stdout, stderr)
 
-	slog.SetDefault(slog.New(&logger))
+	// If in testing mode, set logger via Handler
+	// Otherwise, set default global logger
+	if testing.Testing() {
+		handler, ok := slog.Default().Handler().(*testlogger.Handler)
+		if !ok {
+			panic("Test failed to initialize default logger with Handler")
+		}
+
+		handler.AddInstance(logHandler)
+		defer handler.Delete()
+	} else {
+		slog.SetDefault(slog.New(logHandler))
+	}
+	// ---
 
 	cli.VersionPrinter = func(ctx *cli.Context) {
 		slog.Info("osv-scanner version: " + ctx.App.Version)
@@ -77,7 +93,7 @@ func Run(args []string, stdout, stderr io.Writer) int {
 
 	// if we've been told to print an error, and not already exited with
 	// a specific error code, then exit with a generic non-zero code
-	if logger.HasErrored() {
+	if logHandler.HasErrored() {
 		return 127
 	}
 

cmd/osv-scanner/scan/command_test.go

@@ -9,6 +9,8 @@ import (
 )
 
 func TestCommand(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "",
@@ -241,12 +243,15 @@ func TestCommand(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 func TestCommand_CallAnalysis(t *testing.T) {
+	t.Parallel()
+
 	// Switch to acceptance test if this takes too long, or when we add rust tests
 	// testutility.SkipIfNotAcceptanceTesting(t, "Takes a while to run")
 
@@ -262,12 +267,15 @@ func TestCommand_CallAnalysis(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 func TestCommand_LockfileWithExplicitParseAs(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "unsupported parse-as",
@@ -380,13 +388,16 @@ func TestCommand_LockfileWithExplicitParseAs(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 // TestCommand_GithubActions tests common actions the github actions reusable workflow will run
 func TestCommand_GithubActions(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "scanning osv-scanner custom format",
@@ -401,12 +412,15 @@ func TestCommand_GithubActions(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 func TestCommand_LocalDatabases(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "one specific supported lockfile",
@@ -472,6 +486,7 @@ func TestCommand_LocalDatabases(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			if testutility.IsAcceptanceTesting() {
 				testDir := testutility.CreateTestDir(t)
 				old := tt.Args
@@ -488,6 +503,8 @@ func TestCommand_LocalDatabases(t *testing.T) {
 }
 
 func TestCommand_LocalDatabases_AlwaysOffline(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "a bunch of different lockfiles and ecosystem",
@@ -498,6 +515,7 @@ func TestCommand_LocalDatabases_AlwaysOffline(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testDir := testutility.CreateTestDir(t)
 			old := tt.Args
 			tt.Args = []string{"", "--local-db-path", testDir}
@@ -512,6 +530,8 @@ func TestCommand_LocalDatabases_AlwaysOffline(t *testing.T) {
 }
 
 func TestCommand_Licenses(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "No vulnerabilities with license summary",
@@ -579,15 +599,19 @@ func TestCommand_Licenses(t *testing.T) {
 			Exit: 1,
 		},
 	}
+
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 // Tests all subcommands here.
 func TestCommand_SubCommands(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		// without subcommands
 		{
@@ -609,14 +633,18 @@ func TestCommand_SubCommands(t *testing.T) {
 		},
 		// TODO: add tests for other future subcommands
 	}
+
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 func TestCommand_MavenTransitive(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "scans transitive dependencies for pom.xml by default",
@@ -659,12 +687,15 @@ func TestCommand_MavenTransitive(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}
 }
 
 func TestCommand_MoreLockfiles(t *testing.T) {
+	t.Parallel()
+
 	tests := []testcmd.Case{
 		{
 			Name: "uv.lock",
@@ -704,8 +735,10 @@ func TestCommand_MoreLockfiles(t *testing.T) {
 			},
 		*/
 	}
+
 	for _, tt := range tests {
 		t.Run(tt.Name, func(t *testing.T) {
+			t.Parallel()
 			testcmd.RunAndMatchSnapshots(t, tt)
 		})
 	}

cmd/osv-scanner/scan/image/testmain_test.go

@@ -1,12 +1,15 @@
 package image_test
 
 import (
+	"log/slog"
 	"testing"
 
+	"github.com/google/osv-scanner/v2/internal/testlogger"
 	"github.com/google/osv-scanner/v2/internal/testutility"
 )
 
 func TestMain(m *testing.M) {
+	slog.SetDefault(slog.New(testlogger.New()))
 	m.Run()
 
 	testutility.CleanSnapshots(m)

cmd/osv-scanner/scan/testmain_test.go

@@ -1,12 +1,15 @@
 package scan_test
 
 import (
+	"log/slog"
 	"testing"
 
+	"github.com/google/osv-scanner/v2/internal/testlogger"
 	"github.com/google/osv-scanner/v2/internal/testutility"
 )
 
 func TestMain(m *testing.M) {
+	slog.SetDefault(slog.New(testlogger.New()))
 	m.Run()
 
 	testutility.CleanSnapshots(m)

cmd/osv-scanner/testmain_test.go

@@ -1,10 +1,12 @@
 package main
 
 import (
+	"log/slog"
 	"os"
 	"testing"
 
 	"github.com/go-git/go-git/v5"
+	"github.com/google/osv-scanner/v2/internal/testlogger"
 	"github.com/google/osv-scanner/v2/internal/testutility"
 )
 
@@ -18,6 +20,8 @@ func TestMain(m *testing.M) {
 	if err != nil {
 		panic(err)
 	}
+
+	slog.SetDefault(slog.New(testlogger.New()))
 	m.Run()
 
 	testutility.CleanSnapshots(m)

cmd/osv-scanner/update/testmain_test.go

@@ -1,12 +1,15 @@
 package update_test
 
 import (
+	"log/slog"
 	"testing"
 
+	"github.com/google/osv-scanner/v2/internal/testlogger"
 	"github.com/google/osv-scanner/v2/internal/testutility"
 )
 
 func TestMain(m *testing.M) {
+	slog.SetDefault(slog.New(testlogger.New()))
 	m.Run()
 
 	testutility.CleanSnapshots(m)