From 3f75240a562d88a9411cdd50a2ba24139ca094b7 Mon Sep 17 00:00:00 2001 From: Denis Bilenko Date: Thu, 2 Jan 2025 10:49:21 +0100 Subject: [PATCH] Improve test output to include correct location (#2058) ## Changes - Add t.Helper() in testcli-related helpers, this ensures that output is attributed correctly to test case and not to the helper. - Modify testlcli.Run() to run process in foreground. This is needed for t.Helper to work. - Extend a few assertions with message to help attribute it to proper helper where needed. ## Tests Manually reviewed test output. Before: ``` + go test --timeout 3h -v -run TestDefaultPython/3.9 ./integration/bundle/ === RUN TestDefaultPython === RUN TestDefaultPython/3.9 workspace.go:26: aws golden.go:14: run args: [bundle, init, default-python, --config-file, config.json] runner.go:206: [databricks stderr]: runner.go:206: [databricks stderr]: Welcome to the default Python template for Databricks Asset Bundles! ... testdiff.go:23: Error Trace: /Users/denis.bilenko/work/cli/libs/testdiff/testdiff.go:23 /Users/denis.bilenko/work/cli/libs/testdiff/golden.go:43 /Users/denis.bilenko/work/cli/internal/testcli/golden.go:23 /Users/denis.bilenko/work/cli/integration/bundle/init_default_python_test.go:92 /Users/denis.bilenko/work/cli/integration/bundle/init_default_python_test.go:45 ... ``` After: ``` + go test --timeout 3h -v -run TestDefaultPython/3.9 ./integration/bundle/ === RUN TestDefaultPython === RUN TestDefaultPython/3.9 init_default_python_test.go:51: CLOUD_ENV=aws init_default_python_test.go:92: args: bundle, init, default-python, --config-file, config.json init_default_python_test.go:92: stderr: init_default_python_test.go:92: stderr: Welcome to the default Python template for Databricks Asset Bundles! ... init_default_python_test.go:92: Error Trace: /Users/denis.bilenko/work/cli/libs/testdiff/testdiff.go:24 /Users/denis.bilenko/work/cli/libs/testdiff/golden.go:46 /Users/denis.bilenko/work/cli/internal/testcli/golden.go:23 /Users/denis.bilenko/work/cli/integration/bundle/init_default_python_test.go:92 /Users/denis.bilenko/work/cli/integration/bundle/init_default_python_test.go:45 ... ``` --- integration/internal/acc/workspace.go | 14 +++++--- internal/testcli/golden.go | 5 +-- internal/testcli/runner.go | 47 ++++++++++++++++++++++++--- internal/testutil/interface.go | 2 ++ libs/testdiff/golden.go | 11 +++++-- libs/testdiff/testdiff.go | 4 ++- 6 files changed, 69 insertions(+), 14 deletions(-) diff --git a/integration/internal/acc/workspace.go b/integration/internal/acc/workspace.go index 2f8a5b8e7..64deda7c1 100644 --- a/integration/internal/acc/workspace.go +++ b/integration/internal/acc/workspace.go @@ -21,9 +21,10 @@ type WorkspaceT struct { } func WorkspaceTest(t testutil.TestingT) (context.Context, *WorkspaceT) { + t.Helper() loadDebugEnvIfRunFromIDE(t, "workspace") - t.Log(testutil.GetEnvOrSkipTest(t, "CLOUD_ENV")) + t.Logf("CLOUD_ENV=%s", testutil.GetEnvOrSkipTest(t, "CLOUD_ENV")) w, err := databricks.NewWorkspaceClient() require.NoError(t, err) @@ -41,9 +42,10 @@ func WorkspaceTest(t testutil.TestingT) (context.Context, *WorkspaceT) { // Run the workspace test only on UC workspaces. func UcWorkspaceTest(t testutil.TestingT) (context.Context, *WorkspaceT) { + t.Helper() loadDebugEnvIfRunFromIDE(t, "workspace") - t.Log(testutil.GetEnvOrSkipTest(t, "CLOUD_ENV")) + t.Logf("CLOUD_ENV=%s", testutil.GetEnvOrSkipTest(t, "CLOUD_ENV")) if os.Getenv("TEST_METASTORE_ID") == "" { t.Skipf("Skipping on non-UC workspaces") @@ -67,19 +69,21 @@ func UcWorkspaceTest(t testutil.TestingT) (context.Context, *WorkspaceT) { } func (t *WorkspaceT) TestClusterID() string { + t.Helper() clusterID := testutil.GetEnvOrSkipTest(t, "TEST_BRICKS_CLUSTER_ID") err := t.W.Clusters.EnsureClusterIsRunning(t.ctx, clusterID) - require.NoError(t, err) + require.NoError(t, err, "Unexpected error from EnsureClusterIsRunning for clusterID=%s", clusterID) return clusterID } func (t *WorkspaceT) RunPython(code string) (string, error) { + t.Helper() var err error // Create command executor only once per test. if t.exec == nil { t.exec, err = t.W.CommandExecution.Start(t.ctx, t.TestClusterID(), compute.LanguagePython) - require.NoError(t, err) + require.NoError(t, err, "Unexpected error from CommandExecution.Start(clusterID=%v)", t.TestClusterID()) t.Cleanup(func() { err := t.exec.Destroy(t.ctx) @@ -88,7 +92,7 @@ func (t *WorkspaceT) RunPython(code string) (string, error) { } results, err := t.exec.Execute(t.ctx, code) - require.NoError(t, err) + require.NoError(t, err, "Unexpected error from Execute(%v)", code) require.NotEqual(t, compute.ResultTypeError, results.ResultType, results.Cause) output, ok := results.Data.(string) require.True(t, ok, "unexpected type %T", results.Data) diff --git a/internal/testcli/golden.go b/internal/testcli/golden.go index a16f42c72..669cc2f9b 100644 --- a/internal/testcli/golden.go +++ b/internal/testcli/golden.go @@ -3,7 +3,6 @@ package testcli import ( "context" "fmt" - "strings" "github.com/databricks/cli/internal/testutil" "github.com/databricks/cli/libs/testdiff" @@ -11,7 +10,7 @@ import ( ) func captureOutput(t testutil.TestingT, ctx context.Context, args []string) string { - t.Logf("run args: [%s]", strings.Join(args, ", ")) + t.Helper() r := NewRunner(t, ctx, args...) stdout, stderr, err := r.Run() assert.NoError(t, err) @@ -19,11 +18,13 @@ func captureOutput(t testutil.TestingT, ctx context.Context, args []string) stri } func AssertOutput(t testutil.TestingT, ctx context.Context, args []string, expectedPath string) { + t.Helper() out := captureOutput(t, ctx, args) testdiff.AssertOutput(t, ctx, out, fmt.Sprintf("Output from %v", args), expectedPath) } func AssertOutputJQ(t testutil.TestingT, ctx context.Context, args []string, expectedPath string, ignorePaths []string) { + t.Helper() out := captureOutput(t, ctx, args) testdiff.AssertOutputJQ(t, ctx, out, fmt.Sprintf("Output from %v", args), expectedPath, ignorePaths) } diff --git a/internal/testcli/runner.go b/internal/testcli/runner.go index 95073b57c..52decad2c 100644 --- a/internal/testcli/runner.go +++ b/internal/testcli/runner.go @@ -69,6 +69,7 @@ func consumeLines(ctx context.Context, wg *sync.WaitGroup, r io.Reader) <-chan s } func (r *Runner) registerFlagCleanup(c *cobra.Command) { + r.Helper() // Find target command that will be run. Example: if the command run is `databricks fs cp`, // target command corresponds to `cp` targetCmd, _, err := c.Find(r.args) @@ -230,13 +231,48 @@ func (r *Runner) RunBackground() { } func (r *Runner) Run() (bytes.Buffer, bytes.Buffer, error) { - r.RunBackground() - err := <-r.errch - return r.stdout, r.stderr, err + r.Helper() + var stdout, stderr bytes.Buffer + ctx := cmdio.NewContext(r.ctx, &cmdio.Logger{ + Mode: flags.ModeAppend, + Reader: bufio.Reader{}, + Writer: &stderr, + }) + + cli := cmd.New(ctx) + cli.SetOut(&stdout) + cli.SetErr(&stderr) + cli.SetArgs(r.args) + + r.Logf(" args: %s", strings.Join(r.args, ", ")) + + err := root.Execute(ctx, cli) + if err != nil { + r.Logf(" error: %s", err) + } + + if stdout.Len() > 0 { + // Make a copy of the buffer such that it remains "unread". + scanner := bufio.NewScanner(bytes.NewBuffer(stdout.Bytes())) + for scanner.Scan() { + r.Logf("stdout: %s", scanner.Text()) + } + } + + if stderr.Len() > 0 { + // Make a copy of the buffer such that it remains "unread". + scanner := bufio.NewScanner(bytes.NewBuffer(stderr.Bytes())) + for scanner.Scan() { + r.Logf("stderr: %s", scanner.Text()) + } + } + + return stdout, stderr, err } // Like [require.Eventually] but errors if the underlying command has failed. func (r *Runner) Eventually(condition func() bool, waitFor, tick time.Duration, msgAndArgs ...any) { + r.Helper() ch := make(chan bool, 1) timer := time.NewTimer(waitFor) @@ -269,12 +305,14 @@ func (r *Runner) Eventually(condition func() bool, waitFor, tick time.Duration, } func (r *Runner) RunAndExpectOutput(heredoc string) { + r.Helper() stdout, _, err := r.Run() require.NoError(r, err) require.Equal(r, cmdio.Heredoc(heredoc), strings.TrimSpace(stdout.String())) } func (r *Runner) RunAndParseJSON(v any) { + r.Helper() stdout, _, err := r.Run() require.NoError(r, err) err = json.Unmarshal(stdout.Bytes(), &v) @@ -291,7 +329,7 @@ func NewRunner(t testutil.TestingT, ctx context.Context, args ...string) *Runner } func RequireSuccessfulRun(t testutil.TestingT, ctx context.Context, args ...string) (bytes.Buffer, bytes.Buffer) { - t.Logf("run args: [%s]", strings.Join(args, ", ")) + t.Helper() r := NewRunner(t, ctx, args...) stdout, stderr, err := r.Run() require.NoError(t, err) @@ -299,6 +337,7 @@ func RequireSuccessfulRun(t testutil.TestingT, ctx context.Context, args ...stri } func RequireErrorRun(t testutil.TestingT, ctx context.Context, args ...string) (bytes.Buffer, bytes.Buffer, error) { + t.Helper() r := NewRunner(t, ctx, args...) stdout, stderr, err := r.Run() require.Error(t, err) diff --git a/internal/testutil/interface.go b/internal/testutil/interface.go index 2c3004800..97441212d 100644 --- a/internal/testutil/interface.go +++ b/internal/testutil/interface.go @@ -24,4 +24,6 @@ type TestingT interface { Setenv(key, value string) TempDir() string + + Helper() } diff --git a/libs/testdiff/golden.go b/libs/testdiff/golden.go index c338ac9e5..b67eb50a9 100644 --- a/libs/testdiff/golden.go +++ b/libs/testdiff/golden.go @@ -19,22 +19,25 @@ import ( var OverwriteMode = os.Getenv("TESTS_OUTPUT") == "OVERWRITE" func ReadFile(t testutil.TestingT, ctx context.Context, filename string) string { + t.Helper() data, err := os.ReadFile(filename) if os.IsNotExist(err) { return "" } - assert.NoError(t, err) + assert.NoError(t, err, "Failed to read %s", filename) // On CI, on Windows \n in the file somehow end up as \r\n return NormalizeNewlines(string(data)) } func WriteFile(t testutil.TestingT, filename, data string) { + t.Helper() t.Logf("Overwriting %s", filename) err := os.WriteFile(filename, []byte(data), 0o644) - assert.NoError(t, err) + assert.NoError(t, err, "Failed to write %s", filename) } func AssertOutput(t testutil.TestingT, ctx context.Context, out, outTitle, expectedPath string) { + t.Helper() expected := ReadFile(t, ctx, expectedPath) out = ReplaceOutput(t, ctx, out) @@ -49,6 +52,7 @@ func AssertOutput(t testutil.TestingT, ctx context.Context, out, outTitle, expec } func AssertOutputJQ(t testutil.TestingT, ctx context.Context, out, outTitle, expectedPath string, ignorePaths []string) { + t.Helper() expected := ReadFile(t, ctx, expectedPath) out = ReplaceOutput(t, ctx, out) @@ -69,6 +73,7 @@ var ( ) func ReplaceOutput(t testutil.TestingT, ctx context.Context, out string) string { + t.Helper() out = NormalizeNewlines(out) replacements := GetReplacementsMap(ctx) if replacements == nil { @@ -136,6 +141,7 @@ func GetReplacementsMap(ctx context.Context) *ReplacementsContext { } func PrepareReplacements(t testutil.TestingT, r *ReplacementsContext, w *databricks.WorkspaceClient) { + t.Helper() // in some clouds (gcp) w.Config.Host includes "https://" prefix in others it's really just a host (azure) host := strings.TrimPrefix(strings.TrimPrefix(w.Config.Host, "http://"), "https://") r.Set(host, "$DATABRICKS_HOST") @@ -167,6 +173,7 @@ func PrepareReplacements(t testutil.TestingT, r *ReplacementsContext, w *databri } func PrepareReplacementsUser(t testutil.TestingT, r *ReplacementsContext, u iam.User) { + t.Helper() // There could be exact matches or overlap between different name fields, so sort them by length // to ensure we match the largest one first and map them all to the same token names := []string{ diff --git a/libs/testdiff/testdiff.go b/libs/testdiff/testdiff.go index 1e1df727a..71b781362 100644 --- a/libs/testdiff/testdiff.go +++ b/libs/testdiff/testdiff.go @@ -18,9 +18,10 @@ func UnifiedDiff(filename1, filename2, s1, s2 string) string { } func AssertEqualTexts(t testutil.TestingT, filename1, filename2, expected, out string) { + t.Helper() if len(out) < 1000 && len(expected) < 1000 { // This shows full strings + diff which could be useful when debugging newlines - assert.Equal(t, expected, out) + assert.Equal(t, expected, out, "%s vs %s", filename1, filename2) } else { // only show diff for large texts diff := UnifiedDiff(filename1, filename2, expected, out) @@ -29,6 +30,7 @@ func AssertEqualTexts(t testutil.TestingT, filename1, filename2, expected, out s } func AssertEqualJQ(t testutil.TestingT, expectedName, outName, expected, out string, ignorePaths []string) { + t.Helper() patch, err := jsondiff.CompareJSON([]byte(expected), []byte(out)) if err != nil { t.Logf("CompareJSON error for %s vs %s: %s (fallback to textual comparison)", outName, expectedName, err)