From 304be03e98e8b0a5691d2e0bc1b3c635395fe3eb Mon Sep 17 00:00:00 2001 From: Johan Fylling Date: Mon, 19 Jun 2023 10:51:28 +0200 Subject: [PATCH] cmd: Making `test` watch-mode tests more robust (#6019) * Waiting for output buffer to contain expected data rather than making exact matches on the entire content. * Not aborting watcher on encountered errors Signed-off-by: Johan Fylling --- cmd/test.go | 7 +- cmd/test_test.go | 315 +++++++++++++++++++++++++--------- plugins/status/plugin_test.go | 10 +- util/test/tempus.go | 22 +++ 4 files changed, 267 insertions(+), 87 deletions(-) create mode 100644 util/test/tempus.go diff --git a/cmd/test.go b/cmd/test.go index b861fef75a..ad4d9a07d5 100644 --- a/cmd/test.go +++ b/cmd/test.go @@ -285,8 +285,8 @@ func processWatcherUpdate(ctx context.Context, testParams testCommandParams, pat }) if err != nil { - fmt.Fprintln(os.Stderr, err) - os.Exit(1) + fmt.Fprintln(testParams.output, err) + return } modules := map[string]*ast.Module{} @@ -310,8 +310,7 @@ func processWatcherUpdate(ctx context.Context, testParams testCommandParams, pat }) if err != nil { - fmt.Fprintln(os.Stderr, err) - os.Exit(1) + fmt.Fprintln(testParams.output, err) } } diff --git a/cmd/test_test.go b/cmd/test_test.go index 017dabd187..e2e2cc6931 100644 --- a/cmd/test_test.go +++ b/cmd/test_test.go @@ -8,6 +8,7 @@ import ( "path/filepath" "regexp" "strings" + "sync" "syscall" "testing" "time" @@ -387,7 +388,7 @@ func TestWatchMode(t *testing.T) { } test.WithTempFS(files, func(root string) { - var buf bytes.Buffer + buf := blockingWriter{} testParams := newTestCommandParams() testParams.output = &buf @@ -400,7 +401,13 @@ func TestWatchMode(t *testing.T) { <-done }() - time.Sleep(500 * time.Millisecond) + expected := "Watching for changes ..." + if !test.Eventually(t, 2*time.Second, func() bool { + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // update the test f, _ := os.OpenFile(path.Join(root, "policy_test.rego"), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) @@ -410,7 +417,22 @@ func TestWatchMode(t *testing.T) { } f.Close() - time.Sleep(500 * time.Millisecond) + r := regexp.MustCompile(`FAIL \(.*s\)`) + expected = `%ROOT%/policy_test.rego: +data.foo.test_p: FAIL (%TIME%) +-------------------------------------------------------------------------------- +FAIL: 1/1 +******************************************************************************** +Watching for changes ... +` + if !test.Eventually(t, 2*time.Second, func() bool { + actual := r.ReplaceAllString(buf.String(), "FAIL (%TIME%)") + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(actual, expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // update policy so test passes f, _ = os.OpenFile(path.Join(root, "policy.rego"), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) @@ -421,7 +443,17 @@ func TestWatchMode(t *testing.T) { f.Close() - time.Sleep(500 * time.Millisecond) + expected = `PASS: 1/1 +******************************************************************************** +Watching for changes ... +` + if !test.Eventually(t, 2*time.Second, func() bool { + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // add new policy and test if err := os.WriteFile(path.Join(root, "policy2.rego"), []byte("package bar\n q := \"hello\""), 0644); err != nil { @@ -432,35 +464,20 @@ func TestWatchMode(t *testing.T) { t.Fatal(err) } - time.Sleep(500 * time.Millisecond) - - testParams.stopChan <- syscall.SIGINT - done <- struct{}{} - - expected := `******************************************************************************** -Watching for changes ... -%ROOT%/policy_test.rego: -data.foo.test_p: FAIL (%TIME%) --------------------------------------------------------------------------------- -FAIL: 1/1 + expected = `PASS: 2/2 ******************************************************************************** Watching for changes ... ` - - r := regexp.MustCompile(`FAIL \(.*s\)`) - actual := r.ReplaceAllString(buf.String(), "FAIL (%TIME%)") - expected = strings.ReplaceAll(expected, "%ROOT%", root) - - if !strings.Contains(actual, expected) { - t.Fatalf("Expected:\n\n%s\n\nGot:\n\n%s\n\n", expected, actual) + if !test.Eventually(t, 2*time.Second, func() bool { + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) } + buf.Reset() - // verify output after policy update and new added policy - expected = "PASS: 2/2\n********************************************************************************\nWatching for changes ..." - - if !strings.Contains(buf.String(), expected) { - t.Fatalf("Expected:%s in result but \n\nGot:\n\n%s\n\n", expected, buf.String()) - } + testParams.stopChan <- syscall.SIGINT + done <- struct{}{} }) } @@ -472,7 +489,7 @@ func TestWatchModeWithDataFile(t *testing.T) { } test.WithTempFS(files, func(root string) { - var buf bytes.Buffer + buf := blockingWriter{} testParams := newTestCommandParams() testParams.output = &buf @@ -485,7 +502,13 @@ func TestWatchModeWithDataFile(t *testing.T) { <-done }() - time.Sleep(500 * time.Millisecond) + expected := "Watching for changes ..." + if !test.Eventually(t, 2*time.Second, func() bool { + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // update the data f, _ := os.OpenFile(path.Join(root, "data.json"), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) @@ -495,7 +518,22 @@ func TestWatchModeWithDataFile(t *testing.T) { } f.Close() - time.Sleep(500 * time.Millisecond) + r := regexp.MustCompile(`FAIL \(.*s\)`) + expected = `%ROOT%/policy.rego: +data.foo.test_p: FAIL (%TIME%) +-------------------------------------------------------------------------------- +FAIL: 1/1 +******************************************************************************** +Watching for changes ... +` + if !test.Eventually(t, 2*time.Second, func() bool { + actual := r.ReplaceAllString(buf.String(), "FAIL (%TIME%)") + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(actual, expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // update policy so test passes f, _ = os.OpenFile(path.Join(root, "policy.rego"), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) @@ -506,35 +544,21 @@ func TestWatchModeWithDataFile(t *testing.T) { f.Close() - time.Sleep(500 * time.Millisecond) - - testParams.stopChan <- syscall.SIGINT - done <- struct{}{} - - expected := `******************************************************************************** -Watching for changes ... -%ROOT%/policy.rego: -data.foo.test_p: FAIL (%TIME%) --------------------------------------------------------------------------------- -FAIL: 1/1 + expected = `PASS: 1/1 ******************************************************************************** Watching for changes ... ` - r := regexp.MustCompile(`FAIL \(.*s\)`) - actual := r.ReplaceAllString(buf.String(), "FAIL (%TIME%)") - expected = strings.ReplaceAll(expected, "%ROOT%", root) - - if !strings.Contains(actual, expected) { - t.Fatalf("Expected:\n\n%s\n\nGot:\n\n%s\n\n", expected, actual) + if !test.Eventually(t, 2*time.Second, func() bool { + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) } + buf.Reset() - // verify output after policy update - expected = "PASS: 1/1\n********************************************************************************\nWatching for changes ..." - - if !strings.Contains(buf.String(), expected) { - t.Fatalf("Expected:%s in result but \n\nGot:\n\n%s\n\n", expected, buf.String()) - } + testParams.stopChan <- syscall.SIGINT + done <- struct{}{} }) } @@ -545,7 +569,7 @@ func TestWatchModeWhenDataFileRemoved(t *testing.T) { } test.WithTempFS(files, func(root string) { - var buf bytes.Buffer + buf := blockingWriter{} testParams := newTestCommandParams() testParams.output = &buf @@ -558,7 +582,13 @@ func TestWatchModeWhenDataFileRemoved(t *testing.T) { <-done }() - time.Sleep(500 * time.Millisecond) + expected := "Watching for changes ..." + if !test.Eventually(t, 2*time.Second, func() bool { + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // update the data f, _ := os.OpenFile(path.Join(root, "data.json"), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) @@ -568,7 +598,22 @@ func TestWatchModeWhenDataFileRemoved(t *testing.T) { } f.Close() - time.Sleep(500 * time.Millisecond) + r := regexp.MustCompile(`FAIL \(.*s\)`) + expected = `%ROOT%/policy.rego: +data.foo.test_p: FAIL (%TIME%) +-------------------------------------------------------------------------------- +FAIL: 1/1 +******************************************************************************** +Watching for changes ... +` + if !test.Eventually(t, 2*time.Second, func() bool { + actual := r.ReplaceAllString(buf.String(), "FAIL (%TIME%)") + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(actual, expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // update the data back to the original state, so the opa test passes f, _ = os.OpenFile(path.Join(root, "data.json"), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) @@ -578,7 +623,18 @@ func TestWatchModeWhenDataFileRemoved(t *testing.T) { } f.Close() - time.Sleep(500 * time.Millisecond) + expected = `PASS: 1/1 +******************************************************************************** +Watching for changes ... +` + + if !test.Eventually(t, 2*time.Second, func() bool { + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() // remove the data file, check that test fails afterward err = os.Remove(path.Join(root, "data.json")) @@ -590,24 +646,129 @@ func TestWatchModeWhenDataFileRemoved(t *testing.T) { testParams.stopChan <- syscall.SIGINT done <- struct{}{} - - expected := `PASS: 1/1 -******************************************************************************** -Watching for changes ... -%ROOT%/policy.rego: -data.foo.test_p: FAIL (%TIME%) --------------------------------------------------------------------------------- -FAIL: 1/1 -******************************************************************************** -Watching for changes ... -` - - r := regexp.MustCompile(`FAIL \(.*s\)`) - actual := r.ReplaceAllString(buf.String(), "FAIL (%TIME%)") - expected = strings.ReplaceAll(expected, "%ROOT%", root) - - if !strings.Contains(actual, expected) { - t.Fatalf("Expected:\n\n%s\n\nGot:\n\n%s\n\n", expected, actual) - } }) } + +func TestWatchModeBrokenFileRecovery(t *testing.T) { + + tests := []struct { + note string + fileName string + brokenFile string + fixedFile string + expectedOutput string + }{ + { + note: "empty data file (EOF read by watcher)", + fileName: "data.json", + fixedFile: `{"foo": "bar"}`, + expectedOutput: `1 error occurred during loading: %ROOT%/data.json: EOF +******************************************************************************** +Watching for changes ...`, + }, + { + note: "broken policy", + fileName: "broken_policy.rego", + brokenFile: "package foo\n bar {", + fixedFile: "package foo\n bar {true}", + expectedOutput: `1 error occurred during loading: %ROOT%/broken_policy.rego:2: rego_parse_error: unexpected eof token + bar { + ^ +******************************************************************************** +Watching for changes ...`, + }, + } + + files := map[string]string{ + "/policy.rego": "package foo\n p := 1", + "/policy_test.rego": "package foo\n test_p { p == 1 }", + } + + for _, tc := range tests { + t.Run(tc.note, func(t *testing.T) { + test.WithTempFS(files, func(root string) { + buf := blockingWriter{} + + testParams := newTestCommandParams() + testParams.output = &buf + testParams.watch = true + testParams.count = 1 + + done := make(chan struct{}) + go func() { + _, _ = opaTest([]string{root}, testParams) + <-done + }() + + expected := "Watching for changes ..." + if !test.Eventually(t, 2*time.Second, func() bool { + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() + + // create broken (possibly empty) file + f, _ := os.OpenFile(path.Join(root, tc.fileName), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) + if len(tc.brokenFile) > 0 { + _, err := f.WriteString(tc.brokenFile) + if err != nil { + t.Fatal(err) + } + } + f.Close() + + if !test.Eventually(t, 2*time.Second, func() bool { + expected := strings.ReplaceAll(tc.expectedOutput, "%ROOT%", root) + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", tc.expectedOutput, buf.String()) + } + buf.Reset() + + // write data to empty file + f, _ = os.OpenFile(path.Join(root, tc.fileName), os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0644) + _, err := f.WriteString(tc.fixedFile) + if err != nil { + t.Fatal(err) + } + f.Close() + + expected = "Watching for changes ..." + if !test.Eventually(t, 2*time.Second, func() bool { + expected := strings.ReplaceAll(expected, "%ROOT%", root) + return strings.Contains(buf.String(), expected) + }) { + t.Fatalf("expected:\n\n%q\n\ngot:\n\n%q", expected, buf.String()) + } + buf.Reset() + + testParams.stopChan <- syscall.SIGINT + done <- struct{}{} + }) + }) + } +} + +type blockingWriter struct { + m sync.Mutex + buf bytes.Buffer +} + +func (w *blockingWriter) Write(p []byte) (n int, err error) { + w.m.Lock() + defer w.m.Unlock() + return w.buf.Write(p) +} + +func (w *blockingWriter) String() string { + w.m.Lock() + defer w.m.Unlock() + return w.buf.String() +} + +func (w *blockingWriter) Reset() { + w.m.Lock() + defer w.m.Unlock() + w.buf.Reset() +} diff --git a/plugins/status/plugin_test.go b/plugins/status/plugin_test.go index 5eed71a02f..e337d35a16 100644 --- a/plugins/status/plugin_test.go +++ b/plugins/status/plugin_test.go @@ -24,6 +24,7 @@ import ( "github.com/open-policy-agent/opa/plugins/bundle" inmem "github.com/open-policy-agent/opa/storage/inmem/test" "github.com/open-policy-agent/opa/util" + "github.com/open-policy-agent/opa/util/test" "github.com/open-policy-agent/opa/version" lstat "github.com/open-policy-agent/opa/plugins/logs/status" @@ -148,13 +149,10 @@ func TestPluginPrometheus(t *testing.T) { } func eventually(t *testing.T, predicate func() bool) { - for i := 0; i < 100; i++ { - if predicate() { - return - } - time.Sleep(time.Millisecond * 10) + t.Helper() + if !test.Eventually(t, 1*time.Second, predicate) { + t.Fatal("check took too long") } - t.Fatal("check took too long") } func assertOpInformationGauge(t *testing.T, registerMock *prometheusRegisterMock) { diff --git a/util/test/tempus.go b/util/test/tempus.go new file mode 100644 index 0000000000..6ada673598 --- /dev/null +++ b/util/test/tempus.go @@ -0,0 +1,22 @@ +// Copyright 2023 The OPA Authors. All rights reserved. +// Use of this source code is governed by an Apache2 +// license that can be found in the LICENSE file. + +package test + +import ( + "testing" + "time" +) + +func Eventually(t *testing.T, timeout time.Duration, f func() bool) bool { + t.Helper() + deadline := time.Now().Add(timeout) + for time.Now().Before(deadline) { + if f() { + return true + } + time.Sleep(10 * time.Millisecond) + } + return false +}