From 330ddf4a68f8a9e8a9e42a04d2f48d93b0f4b619 Mon Sep 17 00:00:00 2001 From: apostasie Date: Tue, 15 Apr 2025 14:21:59 -0700 Subject: [PATCH 1/2] Cosmetic fixes for testing debug logs - fix timeout showing 0s instead of default when no explicit timeout is provided - add actual execution time - fix long logs (stdout, stderr) that were showing only the beginning to also show the end - fix formatting issue for "..." - marginally better output for command contextual information Signed-off-by: apostasie --- mod/tigron/internal/com/command.go | 17 ++++++++++------- mod/tigron/internal/formatter/formatter.go | 5 ++++- mod/tigron/test/case.go | 2 +- mod/tigron/test/command.go | 16 +++++++++++++--- 4 files changed, 28 insertions(+), 12 deletions(-) diff --git a/mod/tigron/internal/com/command.go b/mod/tigron/internal/com/command.go index cc8959a7e13..c8cd6c3d21b 100644 --- a/mod/tigron/internal/com/command.go +++ b/mod/tigron/internal/com/command.go @@ -70,6 +70,7 @@ type Result struct { Stderr string ExitCode int Signal os.Signal + Duration time.Duration } type execution struct { @@ -102,9 +103,10 @@ type Command struct { ptyStderr bool ptyStdin bool - exec *execution - mutex sync.Mutex - result *Result + exec *execution + mutex sync.Mutex + result *Result + startTime time.Time } // Clone does just duplicate a command, resetting its execution. @@ -184,12 +186,12 @@ func (gc *Command) Run(parentCtx context.Context) error { ) // Get a timing-out context - timeout := gc.Timeout - if timeout == 0 { - timeout = defaultTimeout + if gc.Timeout == 0 { + gc.Timeout = defaultTimeout } - ctx, ctxCancel = context.WithTimeout(parentCtx, timeout) + ctx, ctxCancel = context.WithTimeout(parentCtx, gc.Timeout) + gc.startTime = time.Now() // Create a contextual command, set the logger cmd = gc.buildCommand(ctx) @@ -366,6 +368,7 @@ func (gc *Command) wrap() error { Stderr: pipes.fromStderr, Environ: cmd.Environ(), Signal: signal, + Duration: time.Since(gc.startTime), } if gc.exec.err == nil { diff --git a/mod/tigron/internal/formatter/formatter.go b/mod/tigron/internal/formatter/formatter.go index 43ce9fe56c4..f0900acbc3f 100644 --- a/mod/tigron/internal/formatter/formatter.go +++ b/mod/tigron/internal/formatter/formatter.go @@ -108,7 +108,10 @@ func chunk(s string, maxLength, maxLines int) []string { } if len(chunks) > maxLines { - chunks = append(chunks[0:maxLines], "...") + abbreviator := "..." + chunks = append( + append(chunks[0:maxLines/2], abbreviator+strings.Repeat(spacer, maxLength-len(abbreviator))), + chunks[len(chunks)-maxLines/2:]...) } else if len(chunks) == 0 { chunks = []string{strings.Repeat(spacer, maxLength)} } diff --git a/mod/tigron/test/case.go b/mod/tigron/test/case.go index 6a703e964a0..5de72442cc4 100644 --- a/mod/tigron/test/case.go +++ b/mod/tigron/test/case.go @@ -233,7 +233,7 @@ func (test *Case) Run(t *testing.T) { "\n\n" + formatter.Table( [][]any{ {startDecorator, fmt.Sprintf("%q: starting test!", test.t.Name())}, - {"cwd", test.Data.TempDir()}, + {"temp", test.Data.TempDir()}, {"config", string(debugConfig)}, {"data", string(debugData)}, }, diff --git a/mod/tigron/test/command.go b/mod/tigron/test/command.go index 0c1970d8d81..9f932bfde67 100644 --- a/mod/tigron/test/command.go +++ b/mod/tigron/test/command.go @@ -39,6 +39,10 @@ const ( exitDecorator = "⚠️" stdoutDecorator = "🟢" stderrDecorator = "🟠" + timeoutDecorator = "⏰" + cwdDecorator = "📁" + envDecorator = "🌱" + sigDecorator = "⚡" ) // CustomizableCommand is an interface meant for people who want to heavily customize the base @@ -193,12 +197,18 @@ func (gc *GenericCommand) Run(expect *Expected) { } if result.Signal != nil { - debug = append(debug, []any{"Signal", result.Signal.String()}) + debug = append(debug, []any{"", sigDecorator + " " + result.Signal.String()}) + } + + duration := result.Duration.String() + if result.Duration < time.Second { + duration = "<1s" } debug = append(debug, - []any{"Limit", gc.cmd.Timeout}, - []any{"Environ", strings.Join(result.Environ, "\n")}, + []any{envDecorator, strings.Join(result.Environ, "\n")}, + []any{timeoutDecorator, duration + " (limit: " + gc.cmd.Timeout.String() + ")"}, + []any{cwdDecorator, gc.cmd.WorkingDir}, ) } From d439da9f06f3cf2b5f83b5bd23980530992f8918 Mon Sep 17 00:00:00 2001 From: apostasie Date: Tue, 15 Apr 2025 21:32:57 -0700 Subject: [PATCH 2/2] Implement env whitelist to reduce debug noise Signed-off-by: apostasie --- mod/tigron/test/command.go | 4 ++++ pkg/testutil/nerdtest/command.go | 19 ++++++++----------- 2 files changed, 12 insertions(+), 11 deletions(-) diff --git a/mod/tigron/test/command.go b/mod/tigron/test/command.go index 9f932bfde67..ecc32e95784 100644 --- a/mod/tigron/test/command.go +++ b/mod/tigron/test/command.go @@ -142,6 +142,10 @@ func (gc *GenericCommand) WithBlacklist(env []string) { gc.cmd.EnvBlackList = env } +func (gc *GenericCommand) WithWhitelist(env []string) { + gc.cmd.EnvWhiteList = env +} + func (gc *GenericCommand) WithTimeout(timeout time.Duration) { gc.cmd.Timeout = timeout } diff --git a/pkg/testutil/nerdtest/command.go b/pkg/testutil/nerdtest/command.go index dbeed949e7c..cf8b7207bd2 100644 --- a/pkg/testutil/nerdtest/command.go +++ b/pkg/testutil/nerdtest/command.go @@ -82,17 +82,14 @@ func newNerdCommand(conf test.Config, t *testing.T) *nerdCommand { } ret.WithBinary(binary) - // Not interested in these - and insulate us from parent environment side effects - ret.WithBlacklist([]string{ - "LS_COLORS", - "DOCKER_CONFIG", - "CONTAINERD_SNAPSHOTTER", - "NERDCTL_TOML", - "CONTAINERD_ADDRESS", - "CNI_PATH", - "NETCONFPATH", - "NERDCTL_EXPERIMENTAL", - "NERDCTL_HOST_GATEWAY_IP", + ret.WithWhitelist([]string{ + "PATH", + "HOME", + "XDG_*", + // Windows needs ProgramData, AppData, etc + "Program*", + "PROGRAM*", + "APPDATA", }) return ret }