diff --git a/cmd/harness/hub_log_router_test.go b/cmd/harness/hub_log_router_test.go index 22d7a3f2..9559e2bc 100644 --- a/cmd/harness/hub_log_router_test.go +++ b/cmd/harness/hub_log_router_test.go @@ -18,7 +18,10 @@ func TestClassifyHubLogLine(t *testing.T) { {line: `dispatch status=error request_id=req-1 err="boom"`, want: hub.LogLevelError}, {line: `hub.auth status=warn action=start err="denied"`, want: hub.LogLevelWarn}, {line: `cmd phase=git name=git stream=stdout b64=SGVsbG8=`, want: hub.LogLevelDebug}, + {line: `dispatch status=start request_id=req-1 skill=code_for_me`, want: hub.LogLevelDebug}, + {line: `dispatch request_id=req-1 stage=clone status=ok repo=git@github.com:acme/repo.git`, want: hub.LogLevelDebug}, {line: `dispatch request_id=req-1 stage=codex status=running elapsed_s=9`, want: hub.LogLevelDebug}, + {line: `dispatch status=ok request_id=req-1 workspace=/tmp/run branch=moltenhub-fix`, want: hub.LogLevelInfo}, {line: `hub.auth status=ok`, want: hub.LogLevelInfo}, } @@ -101,3 +104,38 @@ func TestHubLogRouterWarnLevelSuppressesInfoAndKeepsErrors(t *testing.T) { t.Fatalf("len(snapshot.Events) = %d, want %d", got, want) } } + +func TestHubLogRouterInfoLevelSuppressesHighVolumeDebugLifecycleLogs(t *testing.T) { + t.Parallel() + + sink := &recordingTerminalLogSink{} + var rendered strings.Builder + logger := newTerminalLogger(&rendered, false) + logger.sink = sink + broker := hubui.NewBroker() + router := newHubLogRouter(logger, broker, hub.LogLevelInfo) + + router.Log(`dispatch request_id=req-1 stage=clone status=start repo=git@github.com:acme/repo.git`) + router.Log(`dispatch status=start request_id=req-1 skill=code_for_me`) + router.Log(`hub.auth status=ok`) + + out := rendered.String() + if strings.Contains(out, "stage=clone status=start") { + t.Fatalf("stage debug line rendered at info level: %q", out) + } + if strings.Contains(out, "dispatch status=start request_id=req-1") { + t.Fatalf("dispatch lifecycle debug line rendered at info level: %q", out) + } + if !strings.Contains(out, "hub.auth status=ok") { + t.Fatalf("info line missing from rendered output: %q", out) + } + + if got, want := len(sink.lines), 3; got != want { + t.Fatalf("len(sink.lines) = %d, want %d", got, want) + } + + snapshot := broker.Snapshot() + if got, want := len(snapshot.Events), 1; got != want { + t.Fatalf("len(snapshot.Events) = %d, want %d", got, want) + } +} diff --git a/cmd/harness/main.go b/cmd/harness/main.go index 2319c926..ab6c1d60 100644 --- a/cmd/harness/main.go +++ b/cmd/harness/main.go @@ -779,6 +779,7 @@ func loadHubBootConfig(initPath, configPath string) (hub.InitConfig, int, error) return hub.InitConfig{}, harness.ExitConfig, fmt.Errorf("init config error: %w", err) } cfg.RuntimeConfigPath = hub.ResolveRuntimeConfigPath(initPath) + cfg.LogLevel = configuredHubLogLevel(cfg.LogLevel, cfg.RuntimeConfigPath) return cfg, harness.ExitSuccess, nil } @@ -795,6 +796,31 @@ func loadHubBootConfig(initPath, configPath string) (hub.InitConfig, int, error) return cfg, harness.ExitSuccess, nil } +func configuredHubLogLevel(preferred, runtimeConfigPath string) string { + level := hub.NormalizeLogLevel(preferred) + if level == "" { + level = hub.DefaultLogLevel + } + + runtimeConfigPath = strings.TrimSpace(runtimeConfigPath) + if runtimeConfigPath == "" { + return level + } + + configured := hub.NormalizeLogLevel(hub.ReadRuntimeConfigString(runtimeConfigPath, "log_level", "logLevel", "LOG_LEVEL")) + if configured != "" { + return configured + } + + if runtimeCfg, err := hub.LoadRuntimeConfig(runtimeConfigPath); err == nil { + if configured = hub.NormalizeLogLevel(runtimeCfg.LogLevel); configured != "" { + return configured + } + } + + return level +} + func defaultHubBootConfig(runtimeConfigPath string) (hub.InitConfig, int, error) { cfg := hub.InitConfig{ RuntimeConfigPath: strings.TrimSpace(runtimeConfigPath), @@ -875,13 +901,34 @@ func classifyHubLogLine(line string) hub.LogLevel { return hub.LogLevelDebug } - if isDebugCommandLogLine(line, fields) { + if shouldClassifyHubDebugLine(line, lowerLine, fields, status) { return hub.LogLevelDebug } return hub.LogLevelInfo } +func shouldClassifyHubDebugLine(line, lowerLine string, fields map[string]string, status string) bool { + if isDebugCommandLogLine(line, fields) { + return true + } + if strings.TrimSpace(fields["stage"]) != "" { + return true + } + if strings.HasPrefix(lowerLine, "dispatch status=") && isDebugDispatchStatus(status) { + return true + } + return false +} + +func isDebugDispatchStatus(status string) bool { + switch strings.TrimSpace(status) { + case "start", "ack", "queued", "duplicate", "paused", "resumed", "forced", "running": + return true + default: + return false + } +} func isDebugCommandLogLine(line string, fields map[string]string) bool { if len(fields) == 0 { return false diff --git a/cmd/harness/main_test.go b/cmd/harness/main_test.go index 8884688e..cdd7968b 100644 --- a/cmd/harness/main_test.go +++ b/cmd/harness/main_test.go @@ -2,6 +2,7 @@ package main import ( "context" + "encoding/json" "errors" "fmt" "io" @@ -159,6 +160,70 @@ func TestLoadHubBootConfigWithMissingInitFlagUsesSiblingRuntimeConfigWhenAvailab } } +func TestLoadHubBootConfigWithInitUsesRuntimeConfigLogLevelWhenPresent(t *testing.T) { + t.Setenv("HARNESS_RUNTIME_CONFIG_PATH", "") + + tempDir := t.TempDir() + initPath := filepath.Join(tempDir, "init.json") + runtimeConfigPath := filepath.Join(tempDir, "config.json") + + if err := os.WriteFile(initPath, []byte(`{"base_url":"https://na.hub.molten.bot/v1"}`), 0o600); err != nil { + t.Fatalf("write init config: %v", err) + } + if err := os.WriteFile(runtimeConfigPath, []byte(`{"base_url":"https://na.hub.molten.bot/v1","agent_token":"agent_saved","log_level":"debug"}`), 0o600); err != nil { + t.Fatalf("write runtime config: %v", err) + } + + cfg, exitCode, err := loadHubBootConfig(initPath, "") + if err != nil { + t.Fatalf("loadHubBootConfig() error = %v", err) + } + if exitCode != harness.ExitSuccess { + t.Fatalf("loadHubBootConfig() exitCode = %d, want %d", exitCode, harness.ExitSuccess) + } + if got, want := cfg.LogLevel, hub.LogLevelDebug.String(); got != want { + t.Fatalf("LogLevel = %q, want %q", got, want) + } +} + +func TestLoadHubBootConfigWithInitBackfillsMissingRuntimeConfigLogLevel(t *testing.T) { + t.Setenv("HARNESS_RUNTIME_CONFIG_PATH", "") + + tempDir := t.TempDir() + initPath := filepath.Join(tempDir, "init.json") + runtimeConfigPath := filepath.Join(tempDir, "config.json") + + if err := os.WriteFile(initPath, []byte(`{"base_url":"https://na.hub.molten.bot/v1"}`), 0o600); err != nil { + t.Fatalf("write init config: %v", err) + } + if err := os.WriteFile(runtimeConfigPath, []byte(`{"base_url":"https://na.hub.molten.bot/v1","agent_token":"agent_saved"}`), 0o600); err != nil { + t.Fatalf("write runtime config: %v", err) + } + + cfg, exitCode, err := loadHubBootConfig(initPath, "") + if err != nil { + t.Fatalf("loadHubBootConfig() error = %v", err) + } + if exitCode != harness.ExitSuccess { + t.Fatalf("loadHubBootConfig() exitCode = %d, want %d", exitCode, harness.ExitSuccess) + } + if got, want := cfg.LogLevel, hub.DefaultLogLevel; got != want { + t.Fatalf("LogLevel = %q, want %q", got, want) + } + + data, err := os.ReadFile(runtimeConfigPath) + if err != nil { + t.Fatalf("ReadFile() error = %v", err) + } + var doc map[string]any + if err := json.Unmarshal(data, &doc); err != nil { + t.Fatalf("Unmarshal() error = %v", err) + } + if got, want := doc["log_level"], any(hub.DefaultLogLevel); got != want { + t.Fatalf("config.json log_level = %#v, want %q", got, want) + } +} + func TestLoadHubBootConfigWithMissingConfigFlagFallsBackToRuntimeDefaults(t *testing.T) { t.Setenv("HARNESS_RUNTIME_CONFIG_PATH", "")