From 669998a8f039e25f9f405edc8529a66aacf6e838 Mon Sep 17 00:00:00 2001 From: moltenhub-bot Date: Fri, 10 Apr 2026 22:23:44 -0700 Subject: [PATCH 1/2] Add configurable hub log levels with runtime config defaults --- README.md | 1 + cmd/harness/hub_log_router_test.go | 103 +++++++++++++++++ cmd/harness/main.go | 106 ++++++++++++++++-- init.example.json | 2 + internal/hub/config.go | 42 +++++-- internal/hub/config_test.go | 24 ++++ internal/hub/log_level.go | 77 +++++++++++++ internal/hub/log_level_test.go | 54 +++++++++ internal/hub/runtime_config.go | 57 ++++++++++ .../hub/runtime_config_additional_test.go | 84 ++++++++++++++ internal/hub/runtime_config_test.go | 6 + 11 files changed, 535 insertions(+), 21 deletions(-) create mode 100644 cmd/harness/hub_log_router_test.go create mode 100644 internal/hub/log_level.go create mode 100644 internal/hub/log_level_test.go diff --git a/README.md b/README.md index 29bbbbac..db634c68 100644 --- a/README.md +++ b/README.md @@ -95,6 +95,7 @@ Key fields: - `handle` - `profile.display_name`, `profile.emoji`, `profile.profile` - `agent_harness`, `agent_command` +- `log_level` (`error`, `warn`, `info`, `debug`; default `info`) - `dispatcher.*` - Optional bootstrap secrets: `github_token`, `openai_api_key`, `augment_session_auth` diff --git a/cmd/harness/hub_log_router_test.go b/cmd/harness/hub_log_router_test.go new file mode 100644 index 00000000..22d7a3f2 --- /dev/null +++ b/cmd/harness/hub_log_router_test.go @@ -0,0 +1,103 @@ +package main + +import ( + "strings" + "testing" + + "github.com/jef/moltenhub-code/internal/hub" + "github.com/jef/moltenhub-code/internal/hubui" +) + +func TestClassifyHubLogLine(t *testing.T) { + t.Parallel() + + tests := []struct { + line string + want hub.LogLevel + }{ + {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 request_id=req-1 stage=codex status=running elapsed_s=9`, want: hub.LogLevelDebug}, + {line: `hub.auth status=ok`, want: hub.LogLevelInfo}, + } + + for _, tt := range tests { + tt := tt + t.Run(tt.line, func(t *testing.T) { + t.Parallel() + if got := classifyHubLogLine(tt.line); got != tt.want { + t.Fatalf("classifyHubLogLine(%q) = %v, want %v", tt.line, got, tt.want) + } + }) + } +} + +func TestHubLogRouterFiltersByConfiguredLevel(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(`cmd phase=git name=git stream=stdout b64=SGVsbG8=`) + router.Log(`hub.auth status=ok`) + router.Log(`dispatch status=error request_id=req-1 err="boom"`) + + out := rendered.String() + if strings.Contains(out, "cmd phase=git") { + t.Fatalf("debug cmd 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 !strings.Contains(out, "dispatch status=error") { + t.Fatalf("error line missing from rendered output: %q", out) + } + + if got, want := len(sink.lines), 3; got != want { + t.Fatalf("len(sink.lines) = %d, want %d (%v)", got, want, sink.lines) + } + if got := sink.lines[0]; got != `cmd phase=git name=git stream=stdout b64=SGVsbG8=` { + t.Fatalf("sink.lines[0] = %q", got) + } + + snapshot := broker.Snapshot() + if got, want := len(snapshot.Events), 2; got != want { + t.Fatalf("len(snapshot.Events) = %d, want %d", got, want) + } +} + +func TestHubLogRouterWarnLevelSuppressesInfoAndKeepsErrors(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.LogLevelWarn) + + router.Log(`hub.auth status=ok`) + router.Log(`hub.auth status=warn action=start err="denied"`) + router.Log(`dispatch status=error request_id=req-1 err="boom"`) + + out := rendered.String() + if strings.Contains(out, "hub.auth status=ok") { + t.Fatalf("info line rendered at warn level: %q", out) + } + if !strings.Contains(out, "hub.auth status=warn") { + t.Fatalf("warn line missing from rendered output: %q", out) + } + if !strings.Contains(out, "dispatch status=error") { + t.Fatalf("error line missing from rendered output: %q", out) + } + + snapshot := broker.Snapshot() + if got, want := len(snapshot.Events), 2; 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 59cb6b02..556cf756 100644 --- a/cmd/harness/main.go +++ b/cmd/harness/main.go @@ -238,11 +238,12 @@ func runHub(args []string) int { defer logger.Close() runner := execx.OSRunner{} monitorBroker := hubui.NewBroker() - daemonLogger := func(format string, args ...any) { - line := fmt.Sprintf(format, args...) - logger.Print(line) - monitorBroker.IngestLog(line) + logLevel, err := hub.ParseLogLevel(cfg.LogLevel) + if err != nil { + logLevel = hub.LogLevelInfo } + logRouter := newHubLogRouter(logger, monitorBroker, logLevel) + daemonLogger := logRouter.Printf runtimeCfg, runtimeErr := agentruntime.Resolve(cfg.AgentHarness, cfg.AgentCommand) var authGate agentAuthGate @@ -588,7 +589,7 @@ func runHub(args []string) int { uiServer := hubui.NewServer(*uiListen, monitorBroker) uiServer.AutomaticMode = *uiAutomatic uiServer.ConfiguredHarness = cfg.AgentHarness - uiServer.Logf = logger.Printf + uiServer.Logf = daemonLogger uiServer.LoadLibraryTasks = func() ([]library.TaskSummary, error) { catalog, err := library.LoadCatalog(library.DefaultDir) if err != nil { @@ -681,21 +682,21 @@ func runHub(args []string) int { daemonLogger("dispatch status=stopped request_id=%s err=%q", requestID, errTaskStoppedByOperator) return nil } - logger.Printf("hub.ui status=ready url=%s", monitorURL(*uiListen)) + daemonLogger("hub.ui status=ready url=%s", monitorURL(*uiListen)) prMonitor := &hubui.PRMergeMonitor{ Runner: runner, Broker: monitorBroker, - Logf: logger.Printf, + Logf: daemonLogger, CleanupTask: cleanupTaskLogs, } go func() { if err := prMonitor.Run(ctx); err != nil { - logger.Printf("hub.ui status=warn event=pr_monitor err=%q", err) + daemonLogger("hub.ui status=warn event=pr_monitor err=%q", err) } }() go func() { if err := uiServer.Run(ctx); err != nil { - logger.Printf("hub.ui status=error err=%q", err) + daemonLogger("hub.ui status=error err=%q", err) } }() } @@ -804,6 +805,93 @@ func defaultHubBootConfig(runtimeConfigPath string) (hub.InitConfig, int, error) return cfg, harness.ExitSuccess, nil } +type hubLogRouter struct { + logger *terminalLogger + broker *hubui.Broker + level hub.LogLevel +} + +func newHubLogRouter(logger *terminalLogger, broker *hubui.Broker, level hub.LogLevel) hubLogRouter { + return hubLogRouter{ + logger: logger, + broker: broker, + level: level, + } +} + +func (r hubLogRouter) Printf(format string, args ...any) { + r.Log(strings.TrimSpace(fmt.Sprintf(format, args...))) +} + +func (r hubLogRouter) Log(line string) { + line = strings.TrimSpace(line) + if line == "" { + return + } + + eventLevel := classifyHubLogLine(line) + if !r.level.Allows(eventLevel) { + if r.logger != nil { + // Keep filtered lines in the task mirror for follow-up diagnostics. + r.logger.Capture(line) + } + return + } + + if r.logger != nil { + r.logger.Print(line) + } + if r.broker != nil { + r.broker.IngestLog(line) + } +} + +func classifyHubLogLine(line string) hub.LogLevel { + line = strings.TrimSpace(line) + if line == "" { + return hub.LogLevelInfo + } + + lowerLine := strings.ToLower(line) + if strings.HasPrefix(lowerLine, "error:") { + return hub.LogLevelError + } + if strings.HasPrefix(lowerLine, "warn:") { + return hub.LogLevelWarn + } + if strings.HasPrefix(line, "debug ") { + return hub.LogLevelDebug + } + + fields := parseSimpleKVFields(line) + status := strings.ToLower(strings.TrimSpace(fields["status"])) + switch status { + case "error", "failed", "invalid": + return hub.LogLevelError + case "warn": + return hub.LogLevelWarn + case "running": + return hub.LogLevelDebug + } + + if isDebugCommandLogLine(line, fields) { + return hub.LogLevelDebug + } + + return hub.LogLevelInfo +} + +func isDebugCommandLogLine(line string, fields map[string]string) bool { + if len(fields) == 0 { + return false + } + phase := strings.TrimSpace(fields["phase"]) + if phase == "" { + return false + } + return strings.HasPrefix(line, "cmd ") || strings.Contains(line, " cmd ") +} + func writeStdoutLine(logger *terminalLogger, line string) { line = strings.TrimSpace(line) if line == "" { diff --git a/init.example.json b/init.example.json index 834085a8..5bc3a667 100644 --- a/init.example.json +++ b/init.example.json @@ -10,6 +10,8 @@ // and configure Pi auth/providers separately. Example persisted runtime value: // "pi_provider_auth": "{\"env_var\":\"OPENAI_API_KEY\",\"value\":\"sk-proj_replace_with_your_key\"}", "agent_token": "agent_replace_with_your_token", + // Optional log level: error | warn | info | debug (default: info). + "log_level": "info", "agent_harness": "codex", // optional override when executable name differs from harness default // "agent_command": "codex", diff --git a/internal/hub/config.go b/internal/hub/config.go index 3d014a23..a20d6327 100644 --- a/internal/hub/config.go +++ b/internal/hub/config.go @@ -26,22 +26,23 @@ const ( // InitConfig is the init.json contract for hub runtime mode. type InitConfig struct { - Version string `json:"version"` - BaseURL string `json:"base_url"` - BindToken string `json:"bind_token"` - AgentToken string `json:"agent_token"` - AgentHarness string `json:"agent_harness,omitempty"` - AgentCommand string `json:"agent_command,omitempty"` - SessionKey string `json:"session_key"` - Handle string `json:"handle"` - Profile ProfileConfig `json:"profile"` + Version string `json:"version"` + BaseURL string `json:"base_url"` + BindToken string `json:"bind_token"` + AgentToken string `json:"agent_token"` + LogLevel string `json:"log_level,omitempty"` + AgentHarness string `json:"agent_harness,omitempty"` + AgentCommand string `json:"agent_command,omitempty"` + SessionKey string `json:"session_key"` + Handle string `json:"handle"` + Profile ProfileConfig `json:"profile"` GitHubToken string `json:"github_token,omitempty"` OpenAIAPIKey string `json:"openai_api_key,omitempty"` AugmentSessionAuth string `json:"augment_session_auth,omitempty"` PiProviderAuth string `json:"pi_provider_auth,omitempty"` - Skill SkillConfig `json:"-"` - RuntimeConfigPath string `json:"-"` - Dispatcher DispatcherConfig `json:"dispatcher"` + Skill SkillConfig `json:"-"` + RuntimeConfigPath string `json:"-"` + Dispatcher DispatcherConfig `json:"dispatcher"` } // ProfileConfig controls optional agent profile sync on startup. @@ -136,6 +137,16 @@ func (c *InitConfig) ApplyDefaults() { c.BindToken = strings.TrimSpace(c.BindToken) c.AgentToken = strings.TrimSpace(c.AgentToken) + rawLogLevel := strings.TrimSpace(c.LogLevel) + switch { + case rawLogLevel == "": + c.LogLevel = DefaultLogLevel + case NormalizeLogLevel(rawLogLevel) != "": + c.LogLevel = NormalizeLogLevel(rawLogLevel) + default: + // Preserve invalid value so Validate can return a clear error. + c.LogLevel = strings.ToLower(rawLogLevel) + } c.GitHubToken = strings.TrimSpace(c.GitHubToken) c.OpenAIAPIKey = strings.TrimSpace(c.OpenAIAPIKey) c.AugmentSessionAuth = strings.TrimSpace(c.AugmentSessionAuth) @@ -247,6 +258,13 @@ func (c InitConfig) Validate() error { if strings.TrimSpace(c.Skill.ResultType) == "" { return fmt.Errorf("skill.result_type is required") } + logLevel := strings.TrimSpace(c.LogLevel) + if logLevel == "" { + logLevel = DefaultLogLevel + } + if _, err := ParseLogLevel(logLevel); err != nil { + return err + } if _, err := agentruntime.Resolve(c.AgentHarness, c.AgentCommand); err != nil { return err } diff --git a/internal/hub/config_test.go b/internal/hub/config_test.go index 43237a46..0655c270 100644 --- a/internal/hub/config_test.go +++ b/internal/hub/config_test.go @@ -42,6 +42,9 @@ func TestLoadInitDefaults(t *testing.T) { if cfg.Skill.ResultType != "skill_result" { t.Fatalf("Skill.ResultType = %q", cfg.Skill.ResultType) } + if cfg.LogLevel != DefaultLogLevel { + t.Fatalf("LogLevel = %q, want %q", cfg.LogLevel, DefaultLogLevel) + } if cfg.Dispatcher.MaxParallel < 1 { t.Fatalf("Dispatcher.MaxParallel = %d, want >= 1", cfg.Dispatcher.MaxParallel) } @@ -192,6 +195,27 @@ func TestValidateRejectsInvalidDispatcherThresholds(t *testing.T) { } } +func TestLoadInitRejectsUnknownLogLevel(t *testing.T) { + t.Parallel() + + dir := t.TempDir() + path := filepath.Join(dir, "init.json") + data := `{ + "base_url": "https://na.hub.molten.bot/v1", + "agent_token": "agent_live_token", + "log_level": "chatty" +}` + if err := os.WriteFile(path, []byte(data), 0o644); err != nil { + t.Fatalf("write init: %v", err) + } + + if _, err := LoadInit(path); err == nil { + t.Fatal("LoadInit() error = nil, want invalid log_level error") + } else if !strings.Contains(err.Error(), "log_level must be one of error, warn, info, debug") { + t.Fatalf("LoadInit() error = %v", err) + } +} + func TestLoadInitSupportsAgentHarnessAndCommand(t *testing.T) { t.Parallel() diff --git a/internal/hub/log_level.go b/internal/hub/log_level.go new file mode 100644 index 00000000..e57d5f24 --- /dev/null +++ b/internal/hub/log_level.go @@ -0,0 +1,77 @@ +package hub + +import ( + "fmt" + "strings" +) + +const ( + logLevelErrorValue = "error" + logLevelWarnValue = "warn" + logLevelInfoValue = "info" + logLevelDebugValue = "debug" +) + +// DefaultLogLevel is used when runtime config omits log_level. +const DefaultLogLevel = logLevelInfoValue + +// LogLevel controls log emission severity filtering. +type LogLevel int + +const ( + LogLevelDebug LogLevel = iota + LogLevelInfo + LogLevelWarn + LogLevelError +) + +// ParseLogLevel returns a canonical level enum for a configured value. +func ParseLogLevel(raw string) (LogLevel, error) { + switch NormalizeLogLevel(raw) { + case logLevelErrorValue: + return LogLevelError, nil + case logLevelWarnValue: + return LogLevelWarn, nil + case logLevelInfoValue: + return LogLevelInfo, nil + case logLevelDebugValue: + return LogLevelDebug, nil + default: + return LogLevelInfo, fmt.Errorf("log_level must be one of error, warn, info, debug") + } +} + +// NormalizeLogLevel canonicalizes supported spellings/aliases. +func NormalizeLogLevel(raw string) string { + switch strings.ToLower(strings.TrimSpace(raw)) { + case "err", "error": + return logLevelErrorValue + case "warning", "warn": + return logLevelWarnValue + case "information", "info": + return logLevelInfoValue + case "dbg", "debug": + return logLevelDebugValue + default: + return "" + } +} + +// String returns the canonical lower-case string. +func (l LogLevel) String() string { + switch l { + case LogLevelError: + return logLevelErrorValue + case LogLevelWarn: + return logLevelWarnValue + case LogLevelInfo: + return logLevelInfoValue + default: + return logLevelDebugValue + } +} + +// Allows reports whether an event at eventLevel should be emitted. +func (l LogLevel) Allows(eventLevel LogLevel) bool { + return eventLevel >= l +} diff --git a/internal/hub/log_level_test.go b/internal/hub/log_level_test.go new file mode 100644 index 00000000..05c30539 --- /dev/null +++ b/internal/hub/log_level_test.go @@ -0,0 +1,54 @@ +package hub + +import "testing" + +func TestParseLogLevelSupportsCanonicalValuesAndAliases(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + raw string + want LogLevel + canon string + }{ + {name: "error", raw: "error", want: LogLevelError, canon: "error"}, + {name: "warn", raw: "warning", want: LogLevelWarn, canon: "warn"}, + {name: "info", raw: "INFO", want: LogLevelInfo, canon: "info"}, + {name: "debug", raw: "dbg", want: LogLevelDebug, canon: "debug"}, + } + for _, tt := range tests { + tt := tt + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + got, err := ParseLogLevel(tt.raw) + if err != nil { + t.Fatalf("ParseLogLevel(%q) error = %v", tt.raw, err) + } + if got != tt.want { + t.Fatalf("ParseLogLevel(%q) = %v, want %v", tt.raw, got, tt.want) + } + if got.String() != tt.canon { + t.Fatalf("String() = %q, want %q", got.String(), tt.canon) + } + }) + } +} + +func TestParseLogLevelRejectsUnknown(t *testing.T) { + t.Parallel() + + if _, err := ParseLogLevel("chatty"); err == nil { + t.Fatal("ParseLogLevel(chatty) error = nil, want non-nil") + } +} + +func TestLogLevelAllows(t *testing.T) { + t.Parallel() + + if !LogLevelInfo.Allows(LogLevelWarn) { + t.Fatal("LogLevelInfo should allow warn") + } + if LogLevelWarn.Allows(LogLevelInfo) { + t.Fatal("LogLevelWarn should not allow info") + } +} diff --git a/internal/hub/runtime_config.go b/internal/hub/runtime_config.go index bee20e41..35ea63ad 100644 --- a/internal/hub/runtime_config.go +++ b/internal/hub/runtime_config.go @@ -41,6 +41,7 @@ func (c *RuntimeConfig) UnmarshalJSON(data []byte) error { Token string `json:"token"` SessionKey string `json:"sessionKey"` TimeoutMs int `json:"timeoutMs"` + LogLevel string `json:"logLevel"` } if err := json.Unmarshal(data, &legacy); err != nil { return err @@ -58,6 +59,9 @@ func (c *RuntimeConfig) UnmarshalJSON(data []byte) error { if c.TimeoutMs <= 0 { c.TimeoutMs = legacy.TimeoutMs } + if strings.TrimSpace(c.LogLevel) == "" { + c.LogLevel = legacy.LogLevel + } return nil } @@ -109,6 +113,7 @@ func LoadRuntimeConfig(path string) (RuntimeConfig, error) { if err := cfg.Validate(); err != nil { return RuntimeConfig{}, err } + _ = ensureRuntimeConfigLogLevelPersisted(path, cfg.LogLevel) return cfg, nil } @@ -193,6 +198,7 @@ func SaveRuntimeConfigHubSettings(path string, initCfg InitConfig, resolvedAgent if dispatcherDoc, ok := runtimeConfigDispatcherDoc(initCfg); ok { doc["dispatcher"] = dispatcherDoc } + ensureRuntimeConfigLogLevel(doc, initCfg.LogLevel) encoded, err := json.MarshalIndent(doc, "", " ") if err != nil { @@ -307,6 +313,7 @@ func IncrementRuntimeConfigLibraryTaskUsage(path string, initCfg InitConfig, tas } usage[taskName]++ doc["library_task_usage"] = usage + ensureRuntimeConfigLogLevel(doc, initCfg.LogLevel) encoded, err := json.MarshalIndent(doc, "", " ") if err != nil { @@ -338,6 +345,7 @@ func saveRuntimeConfigStringField( return err } doc[field] = value + ensureRuntimeConfigLogLevel(doc, initCfg.LogLevel) encoded, err := json.MarshalIndent(doc, "", " ") if err != nil { @@ -385,6 +393,54 @@ func docStringValue(v any) string { return strings.TrimSpace(s) } +func ensureRuntimeConfigLogLevel(doc map[string]any, preferred string) { + if doc == nil { + return + } + if existing := runtimeConfigLogLevelFromDoc(doc); existing != "" { + doc["log_level"] = existing + return + } + level := NormalizeLogLevel(preferred) + if level == "" { + level = DefaultLogLevel + } + doc["log_level"] = level +} + +func runtimeConfigLogLevelFromDoc(doc map[string]any) string { + if doc == nil { + return "" + } + for _, key := range []string{"log_level", "logLevel", "LOG_LEVEL"} { + if level := NormalizeLogLevel(docStringValue(doc[key])); level != "" { + return level + } + } + return "" +} + +func ensureRuntimeConfigLogLevelPersisted(path, preferred string) error { + path = strings.TrimSpace(path) + if path == "" { + return nil + } + doc, err := readRuntimeConfigDoc(path) + if err != nil { + return fmt.Errorf("read runtime config: %w", err) + } + if runtimeConfigLogLevelFromDoc(doc) != "" { + return nil + } + ensureRuntimeConfigLogLevel(doc, preferred) + encoded, err := json.MarshalIndent(doc, "", " ") + if err != nil { + return fmt.Errorf("encode runtime config: %w", err) + } + encoded = append(encoded, '\n') + return writeRuntimeConfigFile(path, encoded) +} + func runtimeConfigLibraryTaskUsage(v any) map[string]int { doc, ok := v.(map[string]any) if !ok || len(doc) == 0 { @@ -462,6 +518,7 @@ func SaveRuntimeConfigClaudeOAuthToken(path string, initCfg InitConfig, oauthTok } doc["claude_code_oauth_token"] = oauthToken + ensureRuntimeConfigLogLevel(doc, initCfg.LogLevel) encoded, err := json.MarshalIndent(doc, "", " ") if err != nil { diff --git a/internal/hub/runtime_config_additional_test.go b/internal/hub/runtime_config_additional_test.go index 1cb21753..a1f0eb45 100644 --- a/internal/hub/runtime_config_additional_test.go +++ b/internal/hub/runtime_config_additional_test.go @@ -396,6 +396,38 @@ func TestSaveRuntimeConfigHubSettingsClearsStaleBindTokenForAgentTokenFlow(t *te } } +func TestSaveRuntimeConfigHubSettingsPreservesConfiguredLogLevel(t *testing.T) { + t.Parallel() + + path := filepath.Join(t.TempDir(), ".moltenhub", "config.json") + if err := os.MkdirAll(filepath.Dir(path), 0o755); err != nil { + t.Fatalf("MkdirAll() error = %v", err) + } + if err := os.WriteFile(path, []byte(`{"base_url":"https://na.hub.molten.bot/v1","log_level":"debug"}`), 0o600); err != nil { + t.Fatalf("WriteFile() error = %v", err) + } + + if err := SaveRuntimeConfigHubSettings(path, InitConfig{ + BaseURL: "https://na.hub.molten.bot/v1", + AgentToken: "agent_direct", + }, "agent_direct"); err != nil { + t.Fatalf("SaveRuntimeConfigHubSettings() error = %v", err) + } + + data, err := os.ReadFile(path) + if err != nil { + t.Fatalf("ReadFile() error = %v", err) + } + + var got map[string]any + if err := json.Unmarshal(data, &got); err != nil { + t.Fatalf("Unmarshal() error = %v", err) + } + if got["log_level"] != "debug" { + t.Fatalf("log_level = %#v, want %q", got["log_level"], "debug") + } +} + func TestReadRuntimeConfigString(t *testing.T) { t.Parallel() @@ -433,3 +465,55 @@ func TestReadRuntimeConfigStringInvalidInputs(t *testing.T) { t.Fatalf("ReadRuntimeConfigString(malformed) = %q, want empty", got) } } + +func TestLoadRuntimeConfigBackfillsMissingLogLevel(t *testing.T) { + t.Parallel() + + path := filepath.Join(t.TempDir(), ".moltenhub", "config.json") + if err := os.MkdirAll(filepath.Dir(path), 0o755); err != nil { + t.Fatalf("MkdirAll() error = %v", err) + } + if err := os.WriteFile(path, []byte(`{"base_url":"https://na.hub.molten.bot/v1","agent_token":"agent_saved"}`), 0o600); err != nil { + t.Fatalf("WriteFile() error = %v", err) + } + + got, err := LoadRuntimeConfig(path) + if err != nil { + t.Fatalf("LoadRuntimeConfig() error = %v", err) + } + if got.LogLevel != DefaultLogLevel { + t.Fatalf("LogLevel = %q, want %q", got.LogLevel, DefaultLogLevel) + } + + data, err := os.ReadFile(path) + 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 doc["log_level"] != DefaultLogLevel { + t.Fatalf("log_level = %#v, want %q", doc["log_level"], DefaultLogLevel) + } +} + +func TestLoadRuntimeConfigHonorsConfiguredLogLevel(t *testing.T) { + t.Parallel() + + path := filepath.Join(t.TempDir(), ".moltenhub", "config.json") + if err := os.MkdirAll(filepath.Dir(path), 0o755); err != nil { + t.Fatalf("MkdirAll() error = %v", err) + } + if err := os.WriteFile(path, []byte(`{"base_url":"https://na.hub.molten.bot/v1","agent_token":"agent_saved","log_level":"debug"}`), 0o600); err != nil { + t.Fatalf("WriteFile() error = %v", err) + } + + got, err := LoadRuntimeConfig(path) + if err != nil { + t.Fatalf("LoadRuntimeConfig() error = %v", err) + } + if got.LogLevel != "debug" { + t.Fatalf("LogLevel = %q, want %q", got.LogLevel, "debug") + } +} diff --git a/internal/hub/runtime_config_test.go b/internal/hub/runtime_config_test.go index 9c6af863..b1e522da 100644 --- a/internal/hub/runtime_config_test.go +++ b/internal/hub/runtime_config_test.go @@ -65,6 +65,9 @@ func TestSaveRuntimeConfigWritesExpectedShape(t *testing.T) { if got.TimeoutMs != 20000 { t.Fatalf("TimeoutMs = %d", got.TimeoutMs) } + if got.LogLevel != DefaultLogLevel { + t.Fatalf("LogLevel = %q, want %q", got.LogLevel, DefaultLogLevel) + } if got.Profile.DisplayName != "Molten Bot" { t.Fatalf("Profile.DisplayName = %q", got.Profile.DisplayName) } @@ -188,6 +191,9 @@ func TestLoadRuntimeConfigDefaultsOptionalFieldsWhenMissing(t *testing.T) { if got.TimeoutMs != runtimeTimeoutMs { t.Fatalf("TimeoutMs = %d, want %d", got.TimeoutMs, runtimeTimeoutMs) } + if got.LogLevel != DefaultLogLevel { + t.Fatalf("LogLevel = %q, want %q", got.LogLevel, DefaultLogLevel) + } } func TestLoadRuntimeConfigMissingFile(t *testing.T) { From dada78c10b2a4b6731eaa07479cdd26e864deff5 Mon Sep 17 00:00:00 2001 From: moltenhub-bot Date: Fri, 10 Apr 2026 22:31:23 -0700 Subject: [PATCH 2/2] chore: Layer out the logging -> Error/Warn/Info/Debug -> we have a lot --- cmd/harness/hub_log_router_test.go | 38 +++++++++++++++++ cmd/harness/main.go | 50 ++++++++++++++++++++++- cmd/harness/main_test.go | 65 ++++++++++++++++++++++++++++++ 3 files changed, 152 insertions(+), 1 deletion(-) 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 556cf756..9185d188 100644 --- a/cmd/harness/main.go +++ b/cmd/harness/main.go @@ -778,6 +778,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 } @@ -794,6 +795,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), @@ -874,13 +900,35 @@ 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 cd393915..34eccf41 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", "")