Unified trace system for CLI and TUI observability

.surface

@@ -5350,6 +5350,7 @@ FLAG basecamp tui --quiet type=bool
 FLAG basecamp tui --stats type=bool
 FLAG basecamp tui --styled type=bool
 FLAG basecamp tui --todolist type=string
+FLAG basecamp tui --trace type=bool
 FLAG basecamp tui --verbose type=count
 FLAG basecamp unassign --account type=string
 FLAG basecamp unassign --agent type=bool

bin/devtools

@@ -0,0 +1,50 @@
+#!/usr/bin/env bash
+#
+# Launch the Basecamp TUI with a trace log tailed in a tmux split pane.
+#
+# Usage:
+#   bin/devtools [basecamp-tui-args...]
+#
+# Examples:
+#   bin/devtools                          # Launch TUI + trace tail
+#   bin/devtools 'https://3.basecamp.com/…' # Deep-link into a project
+#
+# Prerequisites: tmux
+#
+# The trace file is created under the standard cache dir. BASECAMP_TRACE is set
+# to the absolute path so the CLI treats it as "TraceAll + custom path".
+
+set -euo pipefail
+
+if ! command -v tmux &>/dev/null; then
+  echo "devtools requires tmux. Install it and try again." >&2
+  exit 1
+fi
+
+# Resolve the basecamp binary (prefer local build, then PATH).
+if [[ -z "${BASECAMP:-}" ]]; then
+  if [[ -x ./bin/basecamp ]]; then
+    BASECAMP=./bin/basecamp
+  elif ! BASECAMP=$(command -v basecamp); then
+    echo "devtools requires the basecamp binary on PATH or BASECAMP=/path/to/basecamp." >&2
+    exit 1
+  fi
+fi
+
+# Unique session name for concurrent launches.
+SESSION="basecamp-devtools-$$"
+
+# Create trace file so tail -f doesn't race the TUI's first write.
+TRACE_DIR="${XDG_CACHE_HOME:-${HOME}/.cache}/basecamp"
+TRACE_FILE="${TRACE_DIR}/trace-devtools-$$.log"
+mkdir -p "$TRACE_DIR"
+: > "$TRACE_FILE"
+
+# tmux new-session and split-window accept shell-command as multiple arguments
+# and exec them directly (no sh -c), so every token stays a discrete argv entry.
+# This avoids all quoting/metacharacter issues with URLs or paths containing
+# spaces, &, etc.
+exec tmux new-session -s "$SESSION" \
+  env "BASECAMP_TRACE=${TRACE_FILE}" "$BASECAMP" tui "$@" \; \
+  split-window -h -l 40% tail -f "$TRACE_FILE" \; \
+  select-pane -t 0

internal/appctx/context.go

@@ -38,6 +38,7 @@ type App struct {
 	// Observability
 	Collector *observability.SessionCollector
 	Hooks     *observability.CLIHooks
+	Tracer    *observability.Tracer
 
 	// Flags holds the global flag values
 	Flags GlobalFlags
@@ -202,6 +203,22 @@ func (a *App) ApplyFlags() {
 	if a.Hooks != nil {
 		a.Hooks.SetLevel(verboseLevel)
 	}
+
+	// Initialize file-based tracer from BASECAMP_TRACE (or BASECAMP_DEBUG backcompat).
+	// Pass the resolved cache dir so trace files land alongside other CLI state.
+	if t := observability.ParseTraceEnvWithCacheDir(a.Config.CacheDir); t != nil {
+		a.Tracer = t
+		if a.Hooks != nil {
+			a.Hooks.SetTracer(t)
+		}
+	}
+}
+
+// Close releases resources held by the App (e.g. trace file handles).
+func (a *App) Close() {
+	if a.Tracer != nil {
+		a.Tracer.Close()
+	}
 }
 
 // OK outputs a success response, automatically including stats if --stats flag is set.

internal/cli/root.go

@@ -101,6 +101,13 @@ func NewRootCmd() *cobra.Command {
 		},
 	}
 
+	cmd.PersistentPostRunE = func(cmd *cobra.Command, args []string) error {
+		if app := appctx.FromContext(cmd.Context()); app != nil {
+			app.Close()
+		}
+		return nil
+	}
+
 	// Allow flags anywhere in the command line
 	cmd.Flags().SetInterspersed(true)
 	cmd.PersistentFlags().SetInterspersed(true)

internal/commands/tui.go

@@ -4,12 +4,14 @@ import (
 	"fmt"
 	"os"
 	"path/filepath"
+	"strings"
 
 	"github.com/spf13/cobra"
 
 	tea "charm.land/bubbletea/v2"
 
 	"github.com/basecamp/basecamp-cli/internal/appctx"
+	"github.com/basecamp/basecamp-cli/internal/observability"
 	"github.com/basecamp/basecamp-cli/internal/tui/workspace"
 	"github.com/basecamp/basecamp-cli/internal/tui/workspace/views"
 	"github.com/basecamp/basecamp-cli/internal/version"
@@ -39,6 +41,48 @@ func NewTUICmd() *cobra.Command {
 				return fmt.Errorf("app not initialized")
 			}
 
+			trace, _ := cmd.Flags().GetBool("trace")
+
+			if trace {
+				if app.Tracer == nil {
+					// No tracer yet — create one with all categories
+					t, err := observability.NewTracer(observability.TraceAll,
+						observability.TracePath(app.Config.CacheDir))
+					if err != nil {
+						fmt.Fprintf(os.Stderr, "Warning: failed to start tracer: %v\n", err)
+					} else {
+						app.Tracer = t
+						if app.Hooks != nil {
+							app.Hooks.SetTracer(t)
+						}
+					}
+				} else {
+					// Env tracer exists but may be narrower (e.g. BASECAMP_TRACE=http).
+					// Widen to all categories so TUI events are captured too.
+					app.Tracer.EnableCategories(observability.TraceAll)
+				}
+			}
+
+			// Print trace path so devtools scripts can find it
+			if app.Tracer != nil {
+				fmt.Fprintf(os.Stderr, "Trace: %s\n", app.Tracer.Path())
+			}
+
+			// Suppress stderr TraceWriter during TUI (TUI owns stderr)
+			if app.Hooks != nil {
+				app.Hooks.SetLevel(0)
+			}
+
+			// Wire bubbletea debug logging to a separate file (plain text,
+			// not the structured JSON trace) so both remain parseable.
+			if app.Tracer != nil && app.Tracer.Enabled(observability.TraceTUI) {
+				debugPath := strings.TrimSuffix(app.Tracer.Path(), ".log") + ".debug.log"
+				f, err := tea.LogToFile(debugPath, "bubbletea")
+				if err == nil {
+					defer f.Close()
+				}
+			}
+
 			session := workspace.NewSession(app)
 			defer session.Shutdown()
 
@@ -51,7 +95,12 @@ func NewTUICmd() *cobra.Command {
 				session.SetInitialView(target, scope)
 			}
 
-			model := workspace.New(session, viewFactory, poolMonitorFactory(session))
+			// Pass tracer to workspace
+			var wsOpts []workspace.Option
+			if app.Tracer != nil {
+				wsOpts = append(wsOpts, workspace.WithTracer(app.Tracer))
+			}
+			model := workspace.New(session, viewFactory, poolMonitorFactory(session), wsOpts...)
 
 			p := tea.NewProgram(model)
 
@@ -61,6 +110,8 @@ func NewTUICmd() *cobra.Command {
 		},
 	}
 
+	cmd.Flags().Bool("trace", false, "Enable trace logging to file")
+
 	return cmd
 }
 

internal/observability/hooks.go

@@ -16,11 +16,15 @@ var _ basecamp.Hooks = (*CLIHooks)(nil)
 //   - 0: Silent (collect stats only, no output)
 //   - 1: Operations only (log SDK operations)
 //   - 2: Operations + requests (log both operations and HTTP requests)
+//
+// An optional Tracer writes structured JSON events to a file,
+// independent of the verbosity level.
 type CLIHooks struct {
 	mu        sync.Mutex
 	level     int
 	collector *SessionCollector
 	writer    *TraceWriter
+	tracer    *Tracer
 }
 
 // NewCLIHooks creates a new CLIHooks with the given verbosity level.
@@ -48,17 +52,27 @@ func (h *CLIHooks) Level() int {
 	return h.level
 }
 
+// SetTracer attaches a file-based Tracer for structured logging.
+func (h *CLIHooks) SetTracer(t *Tracer) {
+	h.mu.Lock()
+	defer h.mu.Unlock()
+	h.tracer = t
+}
+
 // OnOperationStart is called when a semantic SDK operation begins.
 func (h *CLIHooks) OnOperationStart(ctx context.Context, op basecamp.OperationInfo) context.Context {
 	h.mu.Lock()
 	level := h.level
 	writer := h.writer
+	tracer := h.tracer
 	h.mu.Unlock()
 
 	if level >= 1 && writer != nil {
 		writer.WriteOperationStart(op)
 	}
 
+	tracer.Log(TraceHTTP, "operation.start", "service", op.Service, "operation", op.Operation)
+
 	return ctx
 }
 
@@ -68,6 +82,7 @@ func (h *CLIHooks) OnOperationEnd(ctx context.Context, op basecamp.OperationInfo
 	level := h.level
 	collector := h.collector
 	writer := h.writer
+	tracer := h.tracer
 	h.mu.Unlock()
 
 	if collector != nil {
@@ -77,19 +92,30 @@ func (h *CLIHooks) OnOperationEnd(ctx context.Context, op basecamp.OperationInfo
 	if level >= 1 && writer != nil {
 		writer.WriteOperationEnd(op, err, duration)
 	}
+
+	var errStr string
+	if err != nil {
+		errStr = err.Error()
+	}
+	tracer.Log(TraceHTTP, "operation.end",
+		"service", op.Service, "operation", op.Operation,
+		"duration_ms", duration.Milliseconds(), "error", errStr)
 }
 
 // OnRequestStart is called before an HTTP request is sent.
 func (h *CLIHooks) OnRequestStart(ctx context.Context, info basecamp.RequestInfo) context.Context {
 	h.mu.Lock()
 	level := h.level
 	writer := h.writer
+	tracer := h.tracer
 	h.mu.Unlock()
 
 	if level >= 2 && writer != nil {
 		writer.WriteRequestStart(info)
 	}
 
+	tracer.Log(TraceHTTP, "request.start", "method", info.Method, "url", scrubURL(info.URL))
+
 	return ctx
 }
 
@@ -99,6 +125,7 @@ func (h *CLIHooks) OnRequestEnd(ctx context.Context, info basecamp.RequestInfo,
 	collector := h.collector
 	writer := h.writer
 	level := h.level
+	tracer := h.tracer
 	h.mu.Unlock()
 
 	if collector != nil {
@@ -108,6 +135,15 @@ func (h *CLIHooks) OnRequestEnd(ctx context.Context, info basecamp.RequestInfo,
 	if level >= 2 && writer != nil {
 		writer.WriteRequestEnd(info, result)
 	}
+
+	var errStr string
+	if result.Error != nil {
+		errStr = result.Error.Error()
+	}
+	tracer.Log(TraceHTTP, "request.end",
+		"method", info.Method, "url", scrubURL(info.URL),
+		"status", result.StatusCode, "duration_ms", result.Duration.Milliseconds(),
+		"cached", result.FromCache, "error", errStr)
 }
 
 // OnRetry is called before a retry attempt.
@@ -116,6 +152,7 @@ func (h *CLIHooks) OnRetry(ctx context.Context, info basecamp.RequestInfo, attem
 	collector := h.collector
 	writer := h.writer
 	level := h.level
+	tracer := h.tracer
 	h.mu.Unlock()
 
 	if collector != nil {
@@ -125,4 +162,12 @@ func (h *CLIHooks) OnRetry(ctx context.Context, info basecamp.RequestInfo, attem
 	if level >= 2 && writer != nil {
 		writer.WriteRetry(info, attempt, err)
 	}
+
+	var errStr string
+	if err != nil {
+		errStr = err.Error()
+	}
+	tracer.Log(TraceHTTP, "retry",
+		"method", info.Method, "url", scrubURL(info.URL),
+		"attempt", attempt, "error", errStr)
 }

internal/observability/hooks_test.go

@@ -4,11 +4,13 @@ import (
 	"bytes"
 	"context"
 	"errors"
+	"os"
 	"testing"
 	"time"
 
 	"github.com/basecamp/basecamp-sdk/go/pkg/basecamp"
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
 func TestCLIHooks_SetLevel(t *testing.T) {
@@ -203,3 +205,38 @@ func TestCLIHooks_NilWriter(t *testing.T) {
 	assert.Equal(t, 1, summary.TotalOperations)
 	assert.Equal(t, 1, summary.TotalRequests)
 }
+
+func TestCLIHooks_TracerIntegration(t *testing.T) {
+	dir := t.TempDir()
+	path := dir + "/trace.log"
+	tracer, err := NewTracer(TraceHTTP, path)
+	require.NoError(t, err)
+
+	h := NewCLIHooks(0, nil, nil) // level 0 = no stderr output
+	h.SetTracer(tracer)
+
+	ctx := context.Background()
+	op := basecamp.OperationInfo{Service: "Projects", Operation: "List"}
+	ctx = h.OnOperationStart(ctx, op)
+
+	info := basecamp.RequestInfo{Method: "GET", URL: "/projects.json", Attempt: 1}
+	result := basecamp.RequestResult{StatusCode: 200, Duration: 25 * time.Millisecond}
+	reqCtx := h.OnRequestStart(ctx, info)
+	h.OnRequestEnd(reqCtx, info, result)
+
+	h.OnOperationEnd(ctx, op, nil, 30*time.Millisecond)
+
+	tracer.Close()
+
+	data, err := os.ReadFile(path)
+	require.NoError(t, err)
+	output := string(data)
+
+	// Verify structured trace events were written
+	assert.Contains(t, output, "operation.start")
+	assert.Contains(t, output, "operation.end")
+	assert.Contains(t, output, "request.start")
+	assert.Contains(t, output, "request.end")
+	assert.Contains(t, output, "Projects")
+	assert.Contains(t, output, "/projects.json")
+}