log: bound log prints to a Context

The test log adapter is tripping the race detector because it's printing after a test is done. This commit ensures that logs are not printed if a context is canceled.
quay · Dec 16, 2019 · 8788c7d · 8788c7d
1 parent 9737d71
commit 8788c7d
Show file tree

Hide file tree

Showing 13 changed files with 64 additions and 37 deletions.
diff --git a/alpine/fetcher_test.go b/alpine/fetcher_test.go
@@ -11,6 +11,10 @@ import (
 )
 
 func TestFetcher(t *testing.T) {
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
+
 	var table = []struct {
 		release   Release
 		repo      Repo
@@ -24,9 +28,6 @@ func TestFetcher(t *testing.T) {
 	}
 
 	for _, test := range table {
-		ctx := context.Background()
-		logger := log.TestLogger(t)
-		ctx = logger.WithContext(ctx)
 		srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 			http.ServeFile(w, r, test.serveFile)
 		}))

diff --git a/alpine/packagescanner_test.go b/alpine/packagescanner_test.go
@@ -131,9 +131,9 @@ func TestScan(t *testing.T) {
 		},
 	}
 
-	ctx := context.Background()
-	logger := log.TestLogger(t)
-	ctx = logger.WithContext(ctx)
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 	l := &claircore.Layer{
 		Hash: hash,
 	}

diff --git a/alpine/parser_test.go b/alpine/parser_test.go
@@ -10,6 +10,7 @@ import (
 	"github.com/google/go-cmp/cmp"
 
 	"github.com/quay/claircore"
+	"github.com/quay/claircore/test/log"
 )
 
 var V3_10_community_truncated_vulns = []*claircore.Vulnerability{
@@ -160,6 +161,9 @@ var V3_10_community_truncated_vulns = []*claircore.Vulnerability{
 }
 
 func TestParser(t *testing.T) {
+	t.Parallel()
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
 	var table = []struct {
 		release  Release
 		repo     Repo
@@ -176,7 +180,9 @@ func TestParser(t *testing.T) {
 
 	for _, test := range table {
 		t.Run(test.testFile, func(t *testing.T) {
-			t.Parallel()
+			ctx, done := context.WithCancel(ctx)
+			defer done()
+			ctx, _ = log.TestLogger(ctx, t)
 
 			path := fmt.Sprintf("testdata/%s", test.testFile)
 			f, err := os.Open(path)
@@ -188,7 +194,7 @@ func TestParser(t *testing.T) {
 			if err != nil {
 				t.Fatalf("failed to create updater: %v", err)
 			}
-			vulns, err := u.Parse(context.Background(), f)
+			vulns, err := u.Parse(ctx, f)
 			if err != nil {
 				t.Fatalf("failed to parse xml: %v", err)
 			}

diff --git a/dpkg/scanner_test.go b/dpkg/scanner_test.go
@@ -703,9 +703,9 @@ func TestScanner(t *testing.T) {
 			RepositoryHint: "daafc6eba6eae603327bf8fc49645999",
 		},
 	}
-	ctx := context.Background()
-	logger := log.TestLogger(t)
-	ctx = logger.WithContext(ctx)
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 	l := &claircore.Layer{
 		Hash: hash,
 	}

diff --git a/oracle/parser_test.go b/oracle/parser_test.go
@@ -13,8 +13,9 @@ import (
 
 func TestParse(t *testing.T) {
 	t.Parallel()
-	l := log.TestLogger(t)
-	ctx := l.WithContext(context.Background())
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 	u, err := NewUpdater(-1)
 	if err != nil {
 		t.Fatal(err)

diff --git a/oracle/updater_test.go b/oracle/updater_test.go
@@ -11,16 +11,17 @@ import (
 )
 
 func TestFetch(t *testing.T) {
-	ctx := context.Background()
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, l := log.TestLogger(ctx, t)
 	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		http.ServeFile(w, r, "testdata/com.oracle.elsa-2018.xml")
 	}))
-	l := log.TestLogger(t)
 	u, err := NewUpdater(-1, WithLogger(&l), WithURL(srv.URL, ""))
 	if err != nil {
 		t.Fatal(err)
 	}
-	rd, hint, err := u.Fetch(context.Background(), "")
+	rd, hint, err := u.Fetch(ctx, "")
 	if err != nil {
 		t.Error(err)
 	}
@@ -29,7 +30,7 @@ func TestFetch(t *testing.T) {
 		rd.Close()
 	}
 
-	_, fp, err := u.Fetch(l.WithContext(ctx), driver.Fingerprint(hint))
+	_, fp, err := u.Fetch(ctx, driver.Fingerprint(hint))
 	t.Logf("got hint %q", fp)
 	if got, want := err, driver.Unchanged; got != want {
 		t.Errorf("got: %v, want: %v", got, want)

diff --git a/osrelease/scanner_test.go b/osrelease/scanner_test.go
@@ -25,8 +25,9 @@ type parsecase struct {
 
 func (c parsecase) Test(t *testing.T) {
 	t.Parallel()
-	ctx := context.Background()
-	log := log.TestLogger(t)
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, log := log.TestLogger(ctx, t)
 	ctx, task := trace.NewTask(ctx, "parse test")
 	defer task.End()
 	trace.Log(ctx, "parse test:file", c.File)
@@ -181,11 +182,14 @@ func (lc layercase) Prep(t *testing.T) {
 
 func (lc layercase) Test(t *testing.T) {
 	t.Parallel()
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 	s := Scanner{}
 	l := &claircore.Layer{
 		LocalPath: lc.name(),
 	}
-	ds, err := s.Scan(context.Background(), l)
+	ds, err := s.Scan(ctx, l)
 	if err != nil {
 		t.Error(err)
 	}

diff --git a/rhel/fetch_test.go b/rhel/fetch_test.go
@@ -9,17 +9,22 @@ import (
 	"testing"
 
 	"github.com/quay/claircore/libvuln/driver"
+	"github.com/quay/claircore/test/log"
 )
 
 func TestFetch(t *testing.T) {
 	t.Parallel()
-	ctx := context.Background()
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
 	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		http.ServeFile(w, r, "testdata/Red_Hat_Enterprise_Linux_3.xml")
 	}))
 	defer srv.Close()
 
 	t.Run("FetchContext", func(t *testing.T) {
+		ctx, done := context.WithCancel(ctx)
+		defer done()
+		ctx, _ = log.TestLogger(ctx, t)
 		u, err := NewUpdater(3, WithClient(srv.Client()), WithURL(srv.URL, ""))
 		if err != nil {
 			t.Fatal(err)
@@ -49,11 +54,14 @@ func TestFetch(t *testing.T) {
 	})
 
 	t.Run("Fetch", func(t *testing.T) {
+		ctx, done := context.WithCancel(ctx)
+		defer done()
+		ctx, _ = log.TestLogger(ctx, t)
 		u, err := NewUpdater(3, WithClient(srv.Client()), WithURL(srv.URL, ""))
 		if err != nil {
 			t.Fatal(err)
 		}
-		rd, hint, err := u.Fetch(context.Background(), "")
+		rd, hint, err := u.Fetch(ctx, "")
 		if err != nil {
 			t.Fatal(err)
 		}
@@ -67,7 +75,7 @@ func TestFetch(t *testing.T) {
 			t.Fatalf("expected more data than %d bytes", n)
 		}
 
-		rd, got, err := u.Fetch(context.Background(), "")
+		rd, got, err := u.Fetch(ctx, "")
 		t.Logf("got fingerprint: %+v", got)
 		if err != nil {
 			t.Fatal(err)

diff --git a/rhel/matcher_test.go b/rhel/matcher_test.go
@@ -24,9 +24,9 @@ import (
 
 func TestMatcherIntegration(t *testing.T) {
 	integration.Skip(t)
-	ctx := context.Background()
-	logger := log.TestLogger(t)
-	ctx = logger.WithContext(ctx)
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 
 	db, store, _, teardown := vulnstore.TestStore(ctx, t)
 	defer teardown()

diff --git a/rhel/parse_test.go b/rhel/parse_test.go
@@ -13,8 +13,9 @@ import (
 
 func TestParse(t *testing.T) {
 	t.Parallel()
-	l := log.TestLogger(t)
-	ctx := l.WithContext(context.Background())
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 	u, err := NewUpdater(3)
 	if err != nil {
 		t.Fatal(err)

diff --git a/rpm/packagescanner_test.go b/rpm/packagescanner_test.go
@@ -1246,9 +1246,9 @@ func TestScan(t *testing.T) {
 			t.Skipf("skipping test: missing needed utility %q (%v)", exe, err)
 		}
 	}
-	ctx := context.Background()
-	logger := log.TestLogger(t)
-	ctx = logger.WithContext(ctx)
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 	l := &claircore.Layer{
 		Hash: hash,
 	}

diff --git a/suse/integration_test.go b/suse/integration_test.go
@@ -12,8 +12,9 @@ import (
 
 func TestLiveDatabase(t *testing.T) {
 	integration.Skip(t)
-	l := log.TestLogger(t)
-	ctx := l.WithContext(context.Background())
+	ctx, done := context.WithCancel(context.Background())
+	defer done()
+	ctx, _ = log.TestLogger(ctx, t)
 
 	u, err := NewUpdater(EnterpriseServer15)
 	if err != nil {

diff --git a/test/log/log.go b/test/log/log.go
@@ -2,22 +2,26 @@ package log
 
 import (
 	"bufio"
+	"context"
 	"io"
 	"testing"
 
 	"github.com/rs/zerolog"
 )
 
-// TestLogger cross-wires a zerolog.Logger to print to the provided testing.TB.
+// TestLogger cross-wires a zerolog.Logger to print to the provided testing.TB,
+// and returns the logger and associates it with the Context.
 //
 // It is very slow.
-func TestLogger(t testing.TB) zerolog.Logger {
+func TestLogger(ctx context.Context, t testing.TB) (context.Context, zerolog.Logger) {
 	r, w := io.Pipe()
+	log := zerolog.New(zerolog.ConsoleWriter{Out: w, NoColor: true})
 	go func() {
+		defer r.Close()
 		s := bufio.NewScanner(r)
-		for s.Scan() {
+		for s.Scan() && ctx.Err() == nil {
 			t.Log(s.Text())
 		}
 	}()
-	return zerolog.New(zerolog.ConsoleWriter{Out: w, NoColor: true})
+	return log.WithContext(ctx), log
 }