diff --git a/cmd/extension.go b/cmd/extension.go index 19165b54..10ff26c4 100644 --- a/cmd/extension.go +++ b/cmd/extension.go @@ -5,7 +5,6 @@ import ( "errors" "fmt" "os" - "os/exec" "strings" "time" @@ -70,15 +69,11 @@ func dispatchExtension(ctx context.Context, cfg *env.Env, tel *telemetry.Client, start := time.Now() runErr := extension.Invoke(ctx, ext, extArgs, runCtx) - exitCode, errorMsg := 0, "" + exitCode, errorMsg := ExitCode(runErr), "" if runErr != nil { - exitCode, errorMsg = 1, runErr.Error() - var exitErr *exec.ExitError - if errors.As(runErr, &exitErr) { - exitCode = exitErr.ExitCode() - } + errorMsg = runErr.Error() } - tel.EmitCommand(ctx, "ext:"+name, nil, time.Since(start).Milliseconds(), exitCode, errorMsg) + tel.EmitCommand(ctx, "ext:"+name, "", nil, time.Since(start).Milliseconds(), exitCode, errorMsg) return runErr } diff --git a/cmd/instrument_test.go b/cmd/instrument_test.go new file mode 100644 index 00000000..6711fada --- /dev/null +++ b/cmd/instrument_test.go @@ -0,0 +1,215 @@ +package cmd + +import ( + "bytes" + "context" + "encoding/json" + "errors" + "io" + "net/http" + "net/http/httptest" + "os/exec" + "runtime" + "strconv" + "strings" + "testing" + + "github.com/localstack/lstk/internal/env" + "github.com/localstack/lstk/internal/output" + "github.com/localstack/lstk/internal/telemetry" + "github.com/spf13/cobra" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// realExitError produces a genuine *exec.ExitError with the given code, the +// same error shape awscli.Exec returns when a proxied tool exits non-zero. +func realExitError(t *testing.T, code int) error { + t.Helper() + var c *exec.Cmd + if runtime.GOOS == "windows" { + c = exec.Command("cmd", "/c", "exit", strconv.Itoa(code)) + } else { + c = exec.Command("sh", "-c", "exit "+strconv.Itoa(code)) + } + err := c.Run() + require.Error(t, err) + return err +} + +func TestExitCode(t *testing.T) { + t.Run("nil error is 0", func(t *testing.T) { + assert.Equal(t, 0, ExitCode(nil)) + }) + + t.Run("plain error is 1", func(t *testing.T) { + assert.Equal(t, 1, ExitCode(errors.New("boom"))) + }) + + t.Run("proxied exit code unwraps through SilentError", func(t *testing.T) { + err := output.NewSilentError(realExitError(t, 252)) + assert.Equal(t, 252, ExitCode(err)) + }) + + t.Run("json envelope ExitCodeError code is used", func(t *testing.T) { + err := output.NewSilentError(&output.ExitCodeError{Err: errors.New("confirmation required"), Code: 3}) + assert.Equal(t, 3, ExitCode(err)) + }) +} + +func TestProxySubcommand(t *testing.T) { + tests := []struct { + name string + command string + args []string + want string + }{ + { + name: "aws service and operation", + command: "aws", + args: []string{"s3", "ls"}, + want: "s3 ls", + }, + { + name: "aws caps at two tokens so values are never recorded", + command: "aws", + args: []string{"s3", "cp", "file.txt", "s3://bucket"}, + want: "s3 cp", + }, + { + name: "terraform flat command records one token", + command: "terraform", + args: []string{"plan"}, + want: "plan", + }, + { + name: "terraform positional address is not recorded", + command: "terraform", + args: []string{"import", "aws_s3_bucket.customer", "bucket-name"}, + want: "import", + }, + { + name: "terraform nested command records two tokens", + command: "terraform", + args: []string{"state", "rm", "aws_s3_bucket.customer"}, + want: "state rm", + }, + { + name: "cdk stack name is not recorded", + command: "cdk", + args: []string{"deploy", "CustomerStack"}, + want: "deploy", + }, + { + name: "sam function name is not recorded", + command: "sam", + args: []string{"build", "CustomerFunction"}, + want: "build", + }, + { + name: "sam nested command records two tokens", + command: "sam", + args: []string{"local", "invoke", "CustomerFunction"}, + want: "local invoke", + }, + { + name: "az positional search term is not recorded", + command: "az", + args: []string{"find", "customer name"}, + want: "find", + }, + { + name: "empty args", + command: "aws", + args: nil, + want: "", + }, + { + name: "leading double-dash flag stops collection so flag values are never recorded", + command: "aws", + args: []string{"--region", "us-east-1", "s3", "ls"}, + want: "", + }, + { + name: "single-dash flag stops collection", + command: "terraform", + args: []string{"plan", "-json"}, + want: "plan", + }, + { + name: "lstk global flags are stripped first", + command: "aws", + args: []string{"--non-interactive", "s3", "ls"}, + want: "s3 ls", + }, + { + name: "overlong token is truncated", + command: "aws", + args: []string{strings.Repeat("a", 100), "ls"}, + want: strings.Repeat("a", 64) + " ls", + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + assert.Equal(t, tt.want, proxySubcommand(tt.command, tt.args)) + }) + } +} + +func TestCommandInstrumentationRecordsFinalJSONExitCode(t *testing.T) { + events := make(chan map[string]any, 1) + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + body, err := io.ReadAll(r.Body) + if !assert.NoError(t, err) { + w.WriteHeader(http.StatusBadRequest) + return + } + var request struct { + Events []map[string]any `json:"events"` + } + if !assert.NoError(t, json.Unmarshal(body, &request)) { + w.WriteHeader(http.StatusBadRequest) + return + } + for _, event := range request.Events { + events <- event + } + w.WriteHeader(http.StatusOK) + })) + defer srv.Close() + + cfg := &env.Env{JSON: true} + tel := telemetry.NewWithInProcessFlush(srv.URL) + root := &cobra.Command{Use: "lstk", SilenceErrors: true, SilenceUsage: true} + root.AddCommand(&cobra.Command{ + Use: "confirm", + Annotations: map[string]string{jsonSupportedAnnotation: "true"}, + RunE: func(cmd *cobra.Command, _ []string) error { + sink := jsonAwareSink(cmd, cfg, io.Discard) + sink.Emit(output.ErrorEvent{ + Title: "confirmation required", + Code: output.ErrConfirmationRequired, + }) + return output.NewSilentError(errors.New("confirmation required")) + }, + }) + + var stdout bytes.Buffer + configureCommandExecution(root, cfg, tel, &stdout) + root.SetArgs([]string{"confirm"}) + err := root.ExecuteContext(context.Background()) + require.Error(t, err) + assert.Equal(t, 3, ExitCode(err)) + + tel.Close() + select { + case event := <-events: + payload, ok := event["payload"].(map[string]any) + require.True(t, ok) + result, ok := payload["result"].(map[string]any) + require.True(t, ok) + assert.InDelta(t, 3, result["exit_code"], 0) + default: + t.Fatal("no telemetry event received") + } +} diff --git a/cmd/proxy.go b/cmd/proxy.go index 6482fc98..d15db631 100644 --- a/cmd/proxy.go +++ b/cmd/proxy.go @@ -55,6 +55,55 @@ func stripGlobalFlags(args []string) ([]string, globalFlags) { return out, gf } +// proxySubcommand returns the safe leading command-path tokens of a proxy +// command's raw args for telemetry, e.g. "s3 ls" for `lstk aws s3 ls +// s3://bucket`. Only leading non-flag tokens are collected: collection stops at +// the first flag-like arg so a flag's value can never be mistaken for a +// subcommand. The token limit follows each CLI's grammar so a positional value +// is not recorded for flat commands such as `cdk deploy MyStack` or `terraform +// import ADDRESS ID`; each recorded token is capped at 64 runes. +func proxySubcommand(command string, args []string) string { + args, _ = stripGlobalFlags(args) + limit := 1 + if len(args) > 0 { + limit = proxySubcommandTokenLimit(command, args[0]) + } + tokens := make([]string, 0, limit) + for _, arg := range args { + if strings.HasPrefix(arg, "-") { + break + } + if r := []rune(arg); len(r) > 64 { + arg = string(r[:64]) + } + tokens = append(tokens, arg) + if len(tokens) == limit { + break + } + } + return strings.Join(tokens, " ") +} + +func proxySubcommandTokenLimit(command, firstToken string) int { + switch command { + case "aws": + // AWS reserves its first two positions for the service and operation; + // user-supplied values come later. + return 2 + case "terraform": + switch firstToken { + case "metadata", "providers", "state", "workspace": + return 2 + } + case "sam": + switch firstToken { + case "local", "pipeline", "remote": + return 2 + } + } + return 1 +} + // jsonPrecedesCommandName reports whether --json (or --json=) appears in // the raw command line before the literal token calledAs — the resolved proxy // command's own name/alias (e.g. "aws", "terraform"/"tf", "az"). Proxy commands diff --git a/cmd/root.go b/cmd/root.go index 54430688..c6ca4579 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -2,8 +2,11 @@ package cmd import ( "context" + "errors" "fmt" + "io" "os" + "os/exec" "path/filepath" "strings" "time" @@ -287,13 +290,7 @@ func Execute(ctx context.Context) error { root := NewRootCmd(cfg, tel, logger) root.SilenceErrors = true root.SilenceUsage = true - requireJSONSupport(root, cfg) - instrumentCommands(root, tel) - if cfg.TracesEnabled { - wrapCommandsWithTracing(root) - } - wrapCommandsWithJSONEnvelope(root, cfg, os.Stdout) - wrapPreRunEForJSON(root, cfg, os.Stdout) + configureCommandExecution(root, cfg, tel, os.Stdout) if err := root.ExecuteContext(ctx); err != nil { if !output.IsSilent(err) { @@ -304,6 +301,20 @@ func Execute(ctx context.Context) error { return nil } +// configureCommandExecution installs command middleware from innermost to +// outermost. Telemetry must be installed last so it observes the final error +// after JSON output has attached its process exit code; tracing sits outside +// that translation for the same reason. +func configureCommandExecution(root *cobra.Command, cfg *env.Env, tel *telemetry.Client, stdout io.Writer) { + requireJSONSupport(root, cfg) + wrapCommandsWithJSONEnvelope(root, cfg, stdout) + if cfg.TracesEnabled { + wrapCommandsWithTracing(root) + } + instrumentCommands(root, tel) + wrapPreRunEForJSON(root, cfg, stdout) +} + func buildStartOptions(cfg *env.Env, appConfig *config.Config, logger log.Logger, tel *telemetry.Client, persist bool) container.StartOptions { return container.StartOptions{ PlatformClient: api.NewPlatformClient(cfg.APIEndpoint, logger), @@ -494,6 +505,28 @@ func commandDisplayName(c *cobra.Command) string { return strings.TrimPrefix(c.CommandPath(), c.Root().Name()+" ") } +// ExitCode maps a command error to the exit code the lstk process terminates +// with: a proxied tool's *exec.ExitError carries that tool's exact code, an +// output.ExitCodeError carries the --json exit-code convention (3 +// CONFIRMATION_REQUIRED, 4 AUTH_REQUIRED), anything else collapses to 1. +// errors.As unwraps through the SilentError wrapper to reach either type. +// main.go and instrumentCommands both use this, so the telemetry exit_code +// always matches the real process exit code. +func ExitCode(err error) int { + if err == nil { + return 0 + } + var exitErr *exec.ExitError + if errors.As(err, &exitErr) { + return exitErr.ExitCode() + } + var codeErr *output.ExitCodeError + if errors.As(err, &codeErr) { + return codeErr.Code + } + return 1 +} + // instrumentCommands walks the Cobra command tree and wraps every RunE with telemetry emission. func instrumentCommands(cmd *cobra.Command, tel *telemetry.Client) { walkCommandsWithRunE(cmd, func(c *cobra.Command) { @@ -514,14 +547,27 @@ func instrumentCommands(cmd *cobra.Command, tel *telemetry.Client) { flags = append(flags, "--"+f.Name) }) - exitCode := 0 + // Proxy commands disable flag parsing, so their wrapped tool's + // subcommand is invisible in the command path; record its safe + // leading command-path tokens so failures are attributable. + subcommand := "" + if c.DisableFlagParsing { + // Cobra leaves a root flag that preceded a DisableFlagParsing + // command in args. Use the same corrected view as the proxy's + // PreRunE so a global --endpoint-url does not hide the command. + if stripped, _, found := stripPreCommandEndpointURL(c.CalledAs()); found { + args = stripped + } + subcommand = proxySubcommand(c.Name(), args) + } + + exitCode := ExitCode(runErr) errorMsg := "" if runErr != nil { - exitCode = 1 errorMsg = runErr.Error() } - tel.EmitCommand(c.Context(), commandDisplayName(c), flags, time.Since(startTime).Milliseconds(), exitCode, errorMsg) + tel.EmitCommand(c.Context(), commandDisplayName(c), subcommand, flags, time.Since(startTime).Milliseconds(), exitCode, errorMsg) return runErr } @@ -587,13 +633,12 @@ func wrapCommandsWithTracing(cmd *cobra.Command) { c.SetContext(ctx) err := original(c, args) + exitCode := ExitCode(err) if err != nil { span.RecordError(err) span.SetStatus(codes.Error, err.Error()) - span.SetAttributes(attribute.Int("lstk.exit_code", 1)) - } else { - span.SetAttributes(attribute.Int("lstk.exit_code", 0)) } + span.SetAttributes(attribute.Int("lstk.exit_code", exitCode)) return err } }) diff --git a/internal/telemetry/events.go b/internal/telemetry/events.go index 09888bfb..ff3882e4 100644 --- a/internal/telemetry/events.go +++ b/internal/telemetry/events.go @@ -38,10 +38,13 @@ type CommandEvent struct { Result CommandResult `json:"result"` } -// CommandParameters holds the command name and set flags. +// CommandParameters holds the command name and set flags. Subcommand carries +// the safe leading command-path tokens of a proxied tool invocation (e.g. "s3 +// ls" for `lstk aws s3 ls`); empty for lstk's own commands. type CommandParameters struct { - Command string `json:"command"` - Flags []string `json:"flags"` + Command string `json:"command"` + Subcommand string `json:"subcommand,omitempty"` + Flags []string `json:"flags"` } // CommandResult holds the outcome of a command invocation. @@ -74,12 +77,12 @@ const ( // Error codes for start_error lifecycle events. const ( - ErrCodePortConflict = "port_conflict" - ErrCodeImagePullFailed = "image_pull_failed" - ErrCodeLicenseInvalid = "license_invalid" - ErrCodeStartFailed = "start_failed" - ErrCodeStartTimeout = "start_timeout" - ErrCodeEmulatorMismatch = "emulator_mismatch" + ErrCodePortConflict = "port_conflict" + ErrCodeImagePullFailed = "image_pull_failed" + ErrCodeLicenseInvalid = "license_invalid" + ErrCodeStartFailed = "start_failed" + ErrCodeStartTimeout = "start_timeout" + ErrCodeEmulatorMismatch = "emulator_mismatch" ) // ToMap converts a telemetry event struct to a map[string]any for use with Emit. @@ -107,10 +110,10 @@ func (c *Client) GetEnvironment(ctx context.Context) Environment { // EmitCommand emits an lstk_command telemetry event. The Environment block is // populated automatically from the client state. -func (c *Client) EmitCommand(ctx context.Context, command string, flags []string, durationMS int64, exitCode int, errorMsg string) { +func (c *Client) EmitCommand(ctx context.Context, command, subcommand string, flags []string, durationMS int64, exitCode int, errorMsg string) { c.Emit(ctx, "lstk_command", ToMap(CommandEvent{ Environment: c.GetEnvironment(ctx), - Parameters: CommandParameters{Command: command, Flags: flags}, + Parameters: CommandParameters{Command: command, Subcommand: subcommand, Flags: flags}, Result: CommandResult{ DurationMS: durationMS, ExitCode: exitCode, diff --git a/internal/telemetry/events_test.go b/internal/telemetry/events_test.go index e27adcbd..e7d8a581 100644 --- a/internal/telemetry/events_test.go +++ b/internal/telemetry/events_test.go @@ -68,7 +68,7 @@ func TestEmitCommand_SendsCorrectEventNameAndStructure(t *testing.T) { tel, ch := captureEvents(t) tel.SetAuthToken("ls-token") - tel.EmitCommand(context.Background(), "start", []string{"--non-interactive"}, 1200, 0, "") + tel.EmitCommand(context.Background(), "start", "", []string{"--non-interactive"}, 1200, 0, "") got := drainEvent(t, tel, ch) @@ -102,7 +102,7 @@ func TestEmitCommand_SendsCorrectEventNameAndStructure(t *testing.T) { func TestEmitCommand_IncludesErrorMsgOnFailure(t *testing.T) { tel, ch := captureEvents(t) - tel.EmitCommand(context.Background(), "start", nil, 50, 1, "port 4566 already in use") + tel.EmitCommand(context.Background(), "start", "", nil, 50, 1, "port 4566 already in use") got := drainEvent(t, tel, ch) payload := got["payload"].(map[string]any) @@ -111,6 +111,32 @@ func TestEmitCommand_IncludesErrorMsgOnFailure(t *testing.T) { assert.InDelta(t, 1, result["exit_code"], 0) } +func TestEmitCommand_RecordsSubcommandAndRealExitCode(t *testing.T) { + tel, ch := captureEvents(t) + + tel.EmitCommand(context.Background(), "aws", "s3 ls", nil, 80, 252, "exit status 252") + + got := drainEvent(t, tel, ch) + payload := got["payload"].(map[string]any) + params := payload["parameters"].(map[string]any) + assert.Equal(t, "aws", params["command"]) + assert.Equal(t, "s3 ls", params["subcommand"]) + result := payload["result"].(map[string]any) + assert.InDelta(t, 252, result["exit_code"], 0) +} + +func TestEmitCommand_OmitsSubcommandWhenEmpty(t *testing.T) { + tel, ch := captureEvents(t) + + tel.EmitCommand(context.Background(), "start", "", nil, 80, 0, "") + + got := drainEvent(t, tel, ch) + payload := got["payload"].(map[string]any) + params := payload["parameters"].(map[string]any) + _, present := params["subcommand"] + assert.False(t, present, "empty subcommand should be omitted from the payload") +} + func TestEmitCommand_IsNoOpWhenDisabled(t *testing.T) { received := make(chan struct{}, 1) srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { @@ -119,7 +145,7 @@ func TestEmitCommand_IsNoOpWhenDisabled(t *testing.T) { defer srv.Close() tel := New(srv.URL, true) // disabled - tel.EmitCommand(context.Background(), "start", nil, 0, 0, "") + tel.EmitCommand(context.Background(), "start", "", nil, 0, 0, "") tel.Close() select { diff --git a/main.go b/main.go index e151724d..b6676b82 100644 --- a/main.go +++ b/main.go @@ -2,14 +2,11 @@ package main import ( "context" - "errors" "os" - "os/exec" "os/signal" "syscall" "github.com/localstack/lstk/cmd" - "github.com/localstack/lstk/internal/output" ) func main() { @@ -17,20 +14,10 @@ func main() { defer cancel() if err := cmd.Execute(ctx); err != nil { - // A proxied tool (aws, terraform, cdk, sam, az, extensions) exited - // non-zero: propagate its exact code rather than collapsing to 1. - var exitErr *exec.ExitError - if errors.As(err, &exitErr) { - os.Exit(exitErr.ExitCode()) - } - // A JSON-capable command failed after rendering its error envelope to - // stdout: use the --json exit-code convention (3 CONFIRMATION_REQUIRED, - // 4 AUTH_REQUIRED, 1 otherwise) attached by wrapCommandsWithJSONEnvelope. - // errors.As unwraps through the SilentError wrapper to reach it. - var codeErr *output.ExitCodeError - if errors.As(err, &codeErr) { - os.Exit(codeErr.Code) - } - os.Exit(1) + // A proxied tool's exit code (aws, terraform, cdk, sam, az, extensions) + // and the --json exit-code convention are propagated exactly; anything + // else collapses to 1. See cmd.ExitCode, which telemetry shares so the + // recorded exit_code matches the real one. + os.Exit(cmd.ExitCode(err)) } } diff --git a/test/integration/telemetry_test.go b/test/integration/telemetry_test.go index fbc82b3e..e983f2df 100644 --- a/test/integration/telemetry_test.go +++ b/test/integration/telemetry_test.go @@ -10,6 +10,7 @@ import ( "net/http/httptest" "os" "os/exec" + "path/filepath" "runtime" "strings" "sync" @@ -211,6 +212,47 @@ func TestStartCommandDoesNotSendTelemetryWhenDisabled(t *testing.T) { } } +// DEVX-1003: a proxied `lstk aws` failure must record the wrapped CLI's real +// exit code and the leading service/operation tokens in telemetry, instead of +// a flattened exit_code=1 whose only signal is the "exit status 252" string. +func TestAWSProxyTelemetryRecordsExitCodeAndSubcommand(t *testing.T) { + if runtime.GOOS == "windows" { + t.Skip("fake aws shell script not supported on Windows") + } + t.Parallel() + + emulatorSrv := awsHealthServer(t) + defer emulatorSrv.Close() + + analyticsSrv, events := mockAnalyticsServer(t) + + // Fake aws on PATH exiting like the real CLI does on a usage error, so the + // test needs neither the AWS CLI installed nor a real malformed request. + fakeBinDir := t.TempDir() + require.NoError(t, os.WriteFile(filepath.Join(fakeBinDir, "aws"), []byte("#!/bin/sh\nexit 252\n"), 0o755)) + + environ := env.Environ(testEnvWithHome(t.TempDir(), "")). + With(env.AnalyticsEndpoint, analyticsSrv.URL). + With(env.Path, fakeBinDir+string(os.PathListSeparator)+os.Getenv("PATH")) + environ = append(environ, unreachableDockerHost) + + _, _, err := runLstk(t, testContext(t), "", environ, + "--endpoint-url", emulatorSrv.URL, "aws", "s3", "lss") + require.Error(t, err) + requireExitCode(t, 252, err) + + event := receiveEventByName(t, events, "lstk_command") + payload, ok := event["payload"].(map[string]any) + require.True(t, ok) + params, ok := payload["parameters"].(map[string]any) + require.True(t, ok) + assert.Equal(t, "aws", params["command"]) + assert.Equal(t, "s3 lss", params["subcommand"]) + result, ok := payload["result"].(map[string]any) + require.True(t, ok) + assert.InDelta(t, 252, result["exit_code"], 0) +} + // receiveEventByName waits up to 3s for an event with the given name. // Events with a different name are skipped until the deadline. func receiveEventByName(t *testing.T, events <-chan map[string]any, name string) map[string]any {