diff --git a/README.md b/README.md index c30e81b..ed1d137 100644 --- a/README.md +++ b/README.md @@ -200,6 +200,21 @@ Top-level non-resource commands: | 6 | server error (5xx) | | 7 | network / transport failure | +## HTTP diagnostics + +Use `-v` (or `--verbose`) to write one JSON diagnostic per API request to +stderr, including method, URL, HTTP status, elapsed milliseconds, and the +upstream request ID when present. This includes successful calls and every +page fetched by `--all`; the duration includes retries and reading the body. +Transport and body-read failures include an error field. + +Use `-vv` to include request/response headers and bodies. Sensitive header, +query, and JSON field values are redacted. Body diagnostics use the existing +4 MiB cap; an unavailable or oversized request body is reported without +interrupting the API request. Treat detailed output as API data when sharing +it. Stdout remains the operation response, and successful calls produce no +HTTP diagnostics by default. + ## Self-upgrade `twoctl` checks for new releases at most once every 24 hours and prompts when one is available. The prompt offers: diff --git a/cmd/twoctl/cli/diagnostics.go b/cmd/twoctl/cli/diagnostics.go new file mode 100644 index 0000000..25816c8 --- /dev/null +++ b/cmd/twoctl/cli/diagnostics.go @@ -0,0 +1,173 @@ +package cli + +import ( + "bytes" + "encoding/json" + "io" + "net/http" + "net/url" + "strings" + "time" + + "github.com/spf13/cobra" +) + +// beginRequestDiagnostics returns a completion hook shared by ordinary and +// paginated operations. It never changes the API result or consumes a body +// that the request still needs. +func beginRequestDiagnostics(cmd *cobra.Command, req *http.Request) func(*http.Response, []byte, error) { + level := flagVerbose + if level == 0 { + return func(*http.Response, []byte, error) {} + } + started := time.Now() + return func(resp *http.Response, body []byte, err error) { + url := diagnosticURL(req) + record := map[string]any{ + "method": req.Method, "url": url, + "duration_ms": float64(time.Since(started)) / float64(time.Millisecond), + } + if resp != nil { + record["status"] = resp.StatusCode + if id := captureRequestID(resp.Header); id != "" { + record["request_id"] = id + } + } + if err != nil { + message := strings.ReplaceAll(err.Error(), req.URL.String(), url) + record["error"] = secretValueRe.ReplaceAllString(message, "[REDACTED]") + } + if level >= 2 { + addDiagnosticDetails(record, req, resp, body) + } + // A failed diagnostic write must not change the API operation's result. + _ = json.NewEncoder(cmd.ErrOrStderr()).Encode(record) + } +} + +func addDiagnosticDetails(record map[string]any, req *http.Request, resp *http.Response, body []byte) { + record["request_headers"] = diagnosticHeaders(req.Header) + record["request_body"] = diagnosticRequestBody(req) + if resp != nil { + record["response_headers"] = diagnosticHeaders(resp.Header) + record["response_body"] = diagnosticBody(body) + } +} + +func diagnosticURL(req *http.Request) string { + url := *req.URL + query := url.Query() + for key, values := range query { + if sensitiveHeaderRe.MatchString(key) { + query.Set(key, "[REDACTED]") + continue + } + for i, value := range values { + values[i] = secretValueRe.ReplaceAllString(value, "[REDACTED]") + } + } + url.RawQuery = query.Encode() + return url.String() +} + +func diagnosticHeaders(headers http.Header) map[string]string { + out := redactHeaders(headers) + for key := range out { + if sensitiveHeaderRe.MatchString(key) { + out[key] = "[REDACTED]" + } else { + out[key] = secretValueRe.ReplaceAllString(out[key], "[REDACTED]") + } + } + return out +} + +func diagnosticRequestBody(req *http.Request) any { + if req.Body == nil || req.Body == http.NoBody { + return nil + } + if req.GetBody == nil { + return "[body unavailable]" + } + copy, err := req.GetBody() + if err != nil { + return "[body unavailable]" + } + defer copy.Close() + raw, err := io.ReadAll(io.LimitReader(copy, maxResponseBytes+1)) + if err != nil { + return "[body unavailable]" + } + return diagnosticBody(raw) +} + +func diagnosticBody(raw []byte) any { + if len(raw) == 0 { + return nil + } + if len(raw) > maxResponseBytes { + return "[body exceeds diagnostic limit]" + } + decoder := json.NewDecoder(bytes.NewReader(raw)) + decoder.UseNumber() + var value any + if err := decoder.Decode(&value); err != nil { + return redactDiagnosticString(string(raw)) + } + return redactDiagnosticValue(value) +} + +func redactDiagnosticValue(value any) any { + switch value := value.(type) { + case map[string]any: + for key, child := range value { + if sensitiveHeaderRe.MatchString(key) { + value[key] = "[REDACTED]" + } else { + value[key] = redactDiagnosticValue(child) + } + } + case []any: + for i, child := range value { + value[i] = redactDiagnosticValue(child) + } + case string: + return redactDiagnosticString(value) + } + return value +} + +// redactDiagnosticString handles URL-valued body fields as well as API keys. +// Malformed URLs fail closed rather than returning possibly credential-bearing +// text. Only the diagnostic copy is changed. +func redactDiagnosticString(value string) string { + if !strings.Contains(value, "://") && !strings.HasPrefix(value, "/") && !strings.HasPrefix(value, "?") { + return secretValueRe.ReplaceAllString(value, "[REDACTED]") + } + parsed, err := url.Parse(value) + if err != nil { + return "[REDACTED]" + } + query, err := url.ParseQuery(parsed.RawQuery) + if err != nil { + return "[REDACTED]" + } + for key, values := range query { + if sensitiveHeaderRe.MatchString(key) { + query.Set(key, "[REDACTED]") + continue + } + for i, child := range values { + values[i] = secretValueRe.ReplaceAllString(child, "[REDACTED]") + } + } + parsed.RawQuery = query.Encode() + if parsed.User != nil { + parsed.User = url.User("[REDACTED]") + } + if parsed.Fragment != "" { + parsed.Fragment = "[REDACTED]" + parsed.RawFragment = "" + } + return secretValueRe.ReplaceAllString(parsed.String(), "[REDACTED]") +} diff --git a/cmd/twoctl/cli/diagnostics_test.go b/cmd/twoctl/cli/diagnostics_test.go new file mode 100644 index 0000000..7239a4c --- /dev/null +++ b/cmd/twoctl/cli/diagnostics_test.go @@ -0,0 +1,246 @@ +package cli + +import ( + "bytes" + "encoding/json" + "errors" + "fmt" + "io" + "net/http" + "net/http/httptest" + "strings" + "testing" + + "github.com/spf13/cobra" +) + +func TestDiagnosticVerbosityAndRedaction(t *testing.T) { + for _, level := range []int{0, 1, 2} { + t.Run(fmt.Sprintf("level=%d", level), func(t *testing.T) { + checkDiagnosticVerbosity(t, level) + }) + } +} + +func checkDiagnosticVerbosity(t *testing.T, level int) { + t.Helper() + resetGlobals(t) + t.Setenv("TWOCTL_SKIP_UPGRADE_CHECK", "1") + const payload = `{"password":"request-private","note":"secret_test_abcdefghijklmnop","amount":42}` + var sent string + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + raw, _ := io.ReadAll(r.Body) + sent = string(raw) + w.Header().Set("X-Request-Id", "request-123") + w.Header().Set("Set-Cookie", "session=response-private") + fmt.Fprint(w, `{"token":"response-private","payment_link":"https://checkout.two.inc/payment/initiation?token=abc123","id":9007199254740993}`) + })) + defer srv.Close() + args := []string{"--url", srv.URL, "--api-key", "api-private", "order", "create", "--data", payload} + if level > 0 { + args = append(args, "-"+strings.Repeat("v", level)) + } + stdout, stderr, err := runRoot(t, args...) + if err != nil { + t.Fatal(err) + } + if sent != payload || !strings.Contains(stdout, "response-private") { + t.Fatalf("diagnostics changed the request or stdout: body=%s stdout=%s", sent, stdout) + } + if level == 0 { + if stderr != "" { + t.Fatalf("default request produced diagnostics: %s", stderr) + } + return + } + record := decodeDiagnostic(t, stderr) + if record["request_id"] != "request-123" || record["status"] != json.Number("200") || record["duration_ms"] == nil { + t.Fatalf("missing request summary: %v", record) + } + if level == 1 { + if _, exists := record["request_body"]; exists { + t.Fatal("-v included body details") + } + return + } + assertNoDiagnosticSecrets(t, stderr) + response := record["response_body"].(map[string]any) + if response["id"] != json.Number("9007199254740993") { + t.Fatalf("diagnostics lost integer precision: %v", response) + } + if record["request_body"].(map[string]any)["amount"] != json.Number("42") { + t.Fatal("diagnostics omitted non-sensitive request data") + } +} + +func assertNoDiagnosticSecrets(t *testing.T, stderr string) { + t.Helper() + for _, secret := range []string{"api-private", "request-private", "response-private", "abc123", "secret_test_abcdefghijklmnop"} { + if strings.Contains(stderr, secret) { + t.Errorf("detailed diagnostics exposed %q", secret) + } + } +} + +func decodeDiagnostic(t *testing.T, text string) map[string]any { + t.Helper() + decoder := json.NewDecoder(strings.NewReader(text)) + decoder.UseNumber() + var record map[string]any + if err := decoder.Decode(&record); err != nil { + t.Fatalf("invalid JSON diagnostic: %v\n%s", err, text) + } + return record +} + +func TestDiagnosticsIncludeEveryPage(t *testing.T) { + resetGlobals(t) + t.Setenv("TWOCTL_SKIP_UPGRADE_CHECK", "1") + page := 0 + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + page++ + w.Header().Set("X-Trace-Id", fmt.Sprintf("page-%d", page)) + if r.URL.Query().Get("page_cursor") == "" { + fmt.Fprint(w, `{"items":[{"id":1}],"next_page_cursor":"second"}`) + return + } + fmt.Fprint(w, `{"items":[{"id":2}]}`) + })) + defer srv.Close() + stdout, stderr, err := runRoot(t, "--url", srv.URL, "--api-key", "test-key", "billing-statement", "get", "--all", "-v") + if err != nil { + t.Fatal(err) + } + lines := strings.Split(strings.TrimSpace(stderr), "\n") + if len(lines) != 2 || !json.Valid([]byte(stdout)) { + t.Fatalf("expected two diagnostics and JSON stdout: stderr=%s stdout=%s", stderr, stdout) + } + for i, line := range lines { + if decodeDiagnostic(t, line)["request_id"] != fmt.Sprintf("page-%d", i+1) { + t.Fatalf("wrong page request ID: %s", line) + } + } +} + +func TestDiagnosticsIncludeHTTPFailures(t *testing.T) { + for _, all := range []bool{false, true} { + t.Run(fmt.Sprintf("paginated=%t", all), func(t *testing.T) { + resetGlobals(t) + t.Setenv("TWOCTL_SKIP_UPGRADE_CHECK", "1") + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Request-Id", "failed-request") + w.WriteHeader(http.StatusForbidden) + fmt.Fprint(w, `{"error":"denied"}`) + })) + defer srv.Close() + args := []string{"--url", srv.URL, "--api-key", "test-key", "billing-statement", "get", "-v"} + if all { + args = append(args, "--all") + } + _, stderr, err := runRoot(t, args...) + if err == nil { + t.Fatal("expected API failure") + } + record := decodeDiagnostic(t, stderr) + if record["request_id"] != "failed-request" || record["status"] != json.Number("403") { + t.Fatalf("HTTP failure omitted diagnostics: %v", record) + } + }) + } +} + +type diagnosticFailureTransport struct{} + +func (diagnosticFailureTransport) RoundTrip(*http.Request) (*http.Response, error) { + return nil, errors.New("transport unavailable") +} + +func TestDiagnosticsIncludeTransportErrors(t *testing.T) { + resetGlobals(t) + flagVerbose = 2 + var stderr bytes.Buffer + cmd := &cobra.Command{} + cmd.SetErr(&stderr) + req, _ := http.NewRequest(http.MethodGet, "https://example.test?api_key=api-private", nil) + err := executeRequest(cmd, &http.Client{Transport: diagnosticFailureTransport{}}, req) + if err == nil || !strings.Contains(stderr.String(), "transport unavailable") { + t.Fatalf("lost transport failure: %v / %s", err, stderr.String()) + } + if strings.Contains(stderr.String(), "api-private") || req.URL.Query().Get("api_key") != "api-private" { + t.Fatal("diagnostics leaked or modified a sensitive query parameter") + } +} + +func TestDiagnosticBodyLimitsAndUnavailableReplay(t *testing.T) { + req, _ := http.NewRequest(http.MethodPost, "https://example.test", strings.NewReader(strings.Repeat("x", maxResponseBytes+1))) + if got := diagnosticRequestBody(req); got != "[body exceeds diagnostic limit]" { + t.Fatalf("unbounded request diagnostic: %v", got) + } + req.GetBody = nil + if got := diagnosticRequestBody(req); got != "[body unavailable]" { + t.Fatalf("consumed an unreplayable body: %v", got) + } + req.GetBody = func() (io.ReadCloser, error) { return nil, errors.New("cannot replay") } + if got := diagnosticRequestBody(req); got != "[body unavailable]" { + t.Fatalf("replay error not handled: %v", got) + } + if got := diagnosticBody([]byte("plain secret_test_abcdefghijklmnop")); got != "plain [REDACTED]" { + t.Fatalf("plain body secret leaked: %v", got) + } + raw := []byte(`[{"Authorization":"private","nested":["secret_test_abcdefghijklmnop"]}]`) + redacted, _ := json.Marshal(diagnosticBody(raw)) + if strings.Contains(string(redacted), "private") || strings.Contains(string(redacted), "secret_test_") { + t.Fatalf("nested body secrets leaked: %s", redacted) + } +} + +func TestDiagnosticsRedactKeyShapedValuesUnderOrdinaryNames(t *testing.T) { + const key = "secret_test_abcdefghijklmnop" + req, _ := http.NewRequest(http.MethodGet, "https://example.test?note="+key, nil) + req.Header.Set("X-Custom", key) + if strings.Contains(diagnosticURL(req), key) { + t.Fatal("API-key-shaped query value leaked") + } + if diagnosticHeaders(req.Header)["X-Custom"] != "[REDACTED]" { + t.Fatal("API-key-shaped header value leaked") + } + if req.URL.Query().Get("note") != key || req.Header.Get("X-Custom") != key { + t.Fatal("redaction modified the actual request") + } +} + +func TestDiagnosticBodyRedactsURLCredentials(t *testing.T) { + for _, value := range []string{ + "https://checkout.two.inc/payment/initiation?token=abc123&keep=yes", + "https://example.test/?ToKeN=abc123&token=second-secret", + "https://example.test/?%74oken=abc123", + "/payment/initiation?token=abc123", + "?token=abc123", + "https://user:abc123@example.test/path", + "https://example.test/#token=abc123", + "https://example.test/?token=abc123&bad=%zz", + "https://example.test/%zz?token=abc123", + } { + t.Run(value, func(t *testing.T) { + raw, _ := json.Marshal(map[string]any{"payment_link": value, "nested": []any{value}}) + redacted, err := json.Marshal(diagnosticBody(raw)) + if err != nil { + t.Fatal(err) + } + for _, secret := range []string{"abc123", "second-secret"} { + if strings.Contains(string(redacted), secret) { + t.Fatalf("URL credential leaked: %s", redacted) + } + } + if strings.Contains(value, "keep=yes") && !strings.Contains(string(redacted), "keep=yes") { + t.Fatal("redaction removed non-sensitive query data") + } + if got := diagnosticBody([]byte(value)); strings.Contains(fmt.Sprint(got), "abc123") { + t.Fatalf("plain URL credential leaked: %v", got) + } + }) + } + if got := redactDiagnosticString("ordinary text"); got != "ordinary text" { + t.Fatalf("ordinary text changed: %q", got) + } +} diff --git a/cmd/twoctl/cli/extra_test.go b/cmd/twoctl/cli/extra_test.go index 5319829..54dd921 100644 --- a/cmd/twoctl/cli/extra_test.go +++ b/cmd/twoctl/cli/extra_test.go @@ -110,6 +110,7 @@ func TestRunOperationWithRequestBody(t *testing.T) { func TestRunOperationEmptyResponse(t *testing.T) { resetGlobals(t) + t.Setenv("TWOCTL_SKIP_UPGRADE_CHECK", "1") srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusNoContent) })) @@ -120,8 +121,8 @@ func TestRunOperationEmptyResponse(t *testing.T) { if err != nil { t.Fatal(err) } - if !strings.Contains(stderr, "no body") { - t.Errorf("expected 'no body' on stderr: %q", stderr) + if stderr != "" { + t.Errorf("successful no-body response should be quiet: %q", stderr) } } diff --git a/cmd/twoctl/cli/operations.go b/cmd/twoctl/cli/operations.go index 2386000..9fa34b2 100644 --- a/cmd/twoctl/cli/operations.go +++ b/cmd/twoctl/cli/operations.go @@ -521,13 +521,16 @@ func readCappedBody(r io.Reader) ([]byte, error) { } func executeRequest(c *cobra.Command, client *http.Client, req *http.Request) error { + trace := beginRequestDiagnostics(c, req) resp, err := client.Do(req) if err != nil { + trace(nil, nil, err) return &apiError{code: "network", message: err.Error(), exit: ExitNetwork} } defer resp.Body.Close() respBody, err := readCappedBody(resp.Body) + trace(resp, respBody, err) if err != nil { return err } @@ -604,7 +607,6 @@ func readBody(file, data string) ([]byte, error) { func printResponse(cmd *cobra.Command, status int, body []byte) error { if len(body) == 0 { - fmt.Fprintf(cmd.ErrOrStderr(), "HTTP %d (no body)\n", status) return nil } format, err := resolveOutputFormat(cmd) diff --git a/cmd/twoctl/cli/operations_test.go b/cmd/twoctl/cli/operations_test.go index a2d6e98..f0c6ea0 100644 --- a/cmd/twoctl/cli/operations_test.go +++ b/cmd/twoctl/cli/operations_test.go @@ -34,6 +34,7 @@ func resetGlobals(t *testing.T) { flagContext = "" flagURL = "" flagOutput = "json" + flagVerbose = 0 resetCobraFlags(Root()) dir := t.TempDir() t.Setenv("XDG_CONFIG_HOME", dir) diff --git a/cmd/twoctl/cli/paginate.go b/cmd/twoctl/cli/paginate.go index 098291e..8fa458a 100644 --- a/cmd/twoctl/cli/paginate.go +++ b/cmd/twoctl/cli/paginate.go @@ -112,7 +112,7 @@ func fetchAllPages(c *cobra.Command, client *http.Client, baseURL, method, path if err != nil { return nil, err } - raw, err := fetchPage(client, req) + raw, err := fetchPage(c, client, req) if err != nil { return nil, err } @@ -151,13 +151,16 @@ func buildPageRequest(c *cobra.Command, baseURL, method, path string, op *openap return req, nil } -func fetchPage(client *http.Client, req *http.Request) ([]byte, error) { +func fetchPage(c *cobra.Command, client *http.Client, req *http.Request) ([]byte, error) { + trace := beginRequestDiagnostics(c, req) resp, err := client.Do(req) if err != nil { + trace(nil, nil, err) return nil, &apiError{code: "network", message: err.Error(), exit: ExitNetwork} } defer resp.Body.Close() body, err := readCappedBody(resp.Body) + trace(resp, body, err) if err != nil { return nil, err } diff --git a/cmd/twoctl/cli/root.go b/cmd/twoctl/cli/root.go index d5da2ab..352e478 100644 --- a/cmd/twoctl/cli/root.go +++ b/cmd/twoctl/cli/root.go @@ -15,6 +15,7 @@ var ( flagContext string flagURL string flagOutput string + flagVerbose int ) // activeEnv returns the context-selecting flag value, preferring --context @@ -53,6 +54,7 @@ func init() { rootCmd.PersistentFlags().StringVar(&flagContext, "context", "", "alias of --env (kubectl-style)") rootCmd.PersistentFlags().StringVar(&flagURL, "url", "", "raw API base URL (overrides the context's URL)") rootCmd.PersistentFlags().StringVarP(&flagOutput, "output", "o", "auto", "output format: table, json, yaml (auto = table on TTY, json when piped)") + rootCmd.PersistentFlags().CountVarP(&flagVerbose, "verbose", "v", "HTTP diagnostics on stderr (-v timings and IDs; -vv redacted headers and bodies)") rootCmd.Version = httpx.Version }