diff --git a/headroom/cli/init.py b/headroom/cli/init.py index e3ce761ac..6c57581e9 100644 --- a/headroom/cli/init.py +++ b/headroom/cli/init.py @@ -3,10 +3,12 @@ from __future__ import annotations import json +import logging import os import shlex import shutil import subprocess +import sys from hashlib import sha1 from pathlib import Path from typing import Any @@ -29,6 +31,10 @@ from headroom.install.supervisors import start_supervisor from .main import main +logger = logging.getLogger(__name__) + +_VERBOSE_HANDLER_ATTR = "_headroom_init_verbose_handler" + _GLOBAL_PROFILE = "init-user" _CLAUDE_HOOK_MARKER = "headroom-init-claude" _COPILOT_HOOK_MARKER = "headroom-init-copilot" @@ -56,6 +62,26 @@ def _powershell_matcher() -> str: return "Bash|PowerShell" if os.name == "nt" else "Bash" +def _enable_verbose_logging() -> None: + """Attach a stderr handler to the init logger at DEBUG level. + + Idempotent: calling this multiple times in one process (e.g. when nested + subcommands are invoked) leaves exactly one handler attached. Does NOT + mutate stdout; all verbose output goes to stderr so ``headroom init`` + can still be composed in pipes that consume stdout. + """ + + if getattr(logger, _VERBOSE_HANDLER_ATTR, None) is not None: + return + handler = logging.StreamHandler(stream=sys.stderr) + handler.setFormatter(logging.Formatter("[headroom init] %(message)s")) + handler.setLevel(logging.DEBUG) + logger.addHandler(handler) + logger.setLevel(logging.DEBUG) + logger.propagate = False + setattr(logger, _VERBOSE_HANDLER_ATTR, handler) + + def _local_profile(cwd: Path | None = None) -> str: root = (cwd or Path.cwd()).resolve() slug = "".join(ch if ch.isalnum() or ch in "-._" else "-" for ch in root.name.lower()).strip( @@ -100,11 +126,13 @@ def _json_file(path: Path) -> dict[str, Any]: def _write_json(path: Path, payload: dict[str, Any]) -> None: + logger.debug("write json: %s (keys=%s)", path, sorted(payload.keys())) path.parent.mkdir(parents=True, exist_ok=True) path.write_text(json.dumps(payload, indent=2) + "\n", encoding="utf-8") def _ensure_claude_hooks(path: Path, profile: str, port: int) -> None: + logger.debug("ensure claude hooks: %s (profile=%s, port=%s)", path, profile, port) payload = _json_file(path) env_map = dict(payload.get("env") or {}) if isinstance(payload.get("env"), dict) else {} env_map["ANTHROPIC_BASE_URL"] = f"http://127.0.0.1:{port}" @@ -152,6 +180,7 @@ def _ensure_claude_hooks(path: Path, profile: str, port: int) -> None: def _ensure_copilot_hooks(path: Path, profile: str) -> None: + logger.debug("ensure copilot hooks: %s (profile=%s)", path, profile) payload = _json_file(path) hooks = dict(payload.get("hooks") or {}) if isinstance(payload.get("hooks"), dict) else {} command = f"{_hook_command('--profile', profile)} --marker {_COPILOT_HOOK_MARKER}" @@ -179,6 +208,7 @@ def _replace_marker_block(content: str, marker_start: str, marker_end: str, bloc def _ensure_codex_provider(path: Path, port: int) -> None: + logger.debug("ensure codex provider block: %s (port=%s)", path, port) block = ( f"{_CODEX_PROVIDER_MARKER_START}\n" 'model_provider = "headroom"\n\n' @@ -256,6 +286,7 @@ def _ensure_codex_feature_flag(path: Path) -> None: def _ensure_codex_hooks(path: Path, profile: str) -> None: + logger.debug("ensure codex hooks: %s (profile=%s)", path, profile) command = f"{_hook_command('--profile', profile)} --marker {_CODEX_HOOK_MARKER}" payload = { "hooks": { @@ -368,6 +399,8 @@ def _apply_user_env(values: dict[str, str]) -> None: manifest = _env_manifest(values) manifest.base_env = {} manifest.tool_envs = {"copilot": values} + scope = "windows" if os.name == "nt" else "unix" + logger.debug("apply user env scope=%s keys=%s", scope, sorted(values.keys())) if os.name == "nt": _apply_windows_env_scope(manifest) else: @@ -398,6 +431,7 @@ def _marketplace_source() -> str: def _run_checked(command: list[str], *, action: str) -> None: + logger.debug("subprocess [%s]: %s", action, _command_string(command)) result = subprocess.run( command, capture_output=True, @@ -405,10 +439,20 @@ def _run_checked(command: list[str], *, action: str) -> None: encoding="utf-8", errors="replace", ) + logger.debug( + "subprocess [%s] exit=%s stdout=%r stderr=%r", + action, + result.returncode, + result.stdout[:200], + result.stderr[:200], + ) if result.returncode == 0: return detail = "\n".join(part for part in (result.stderr.strip(), result.stdout.strip()) if part) if "already" in detail.lower() or "exists" in detail.lower(): + logger.debug( + "subprocess [%s] non-zero exit tolerated ('already'/'exists' detected)", action + ) return raise click.ClickException(f"{action} failed: {detail or result.returncode}") @@ -470,11 +514,18 @@ def _probe_init_targets(global_scope: bool) -> list[tuple[str, str | None]]: """ allowed = _GLOBAL_TARGETS if global_scope else _LOCAL_TARGETS + logger.debug( + "detect_init_targets: global_scope=%s allowed=%s", + global_scope, + sorted(allowed), + ) probes: list[tuple[str, str | None]] = [] for target in _SUPPORTED_TARGETS: if target not in allowed: continue - probes.append((target, shutil.which(target))) + path = shutil.which(target) + logger.debug("detect_init_targets: shutil.which(%r) -> %s", target, path or "None") + probes.append((target, path)) return probes @@ -580,6 +631,14 @@ def _run_init_targets( region: str | None, memory: bool, ) -> None: + logger.debug( + "run_init_targets: targets=%s global_scope=%s port=%s backend=%s memory=%s", + targets, + global_scope, + port, + backend, + memory, + ) runtime_targets = [target for target in targets if target != "openclaw"] profile = _ensure_runtime_manifest( global_scope=global_scope, @@ -590,7 +649,9 @@ def _run_init_targets( region=region, memory=memory, ) + logger.debug("run_init_targets: using profile=%s", profile) for target in targets: + logger.debug("run_init_targets: dispatching -> %s", target) if target == "claude": _init_claude(global_scope=global_scope, profile=profile, port=port) elif target == "copilot": @@ -608,6 +669,13 @@ def _run_init_targets( @click.option("--anyllm-provider", default=None, help="Provider for any-llm backends.") @click.option("--region", default=None, help="Cloud region for Bedrock / Vertex style backends.") @click.option("--memory", is_flag=True, help="Enable persistent memory in the proxy runtime.") +@click.option( + "-v", + "--verbose", + is_flag=True, + help="Emit debug-level diagnostics to stderr (flag values, shutil.which results, " + "file paths touched, subprocess invocations and exit codes).", +) @click.pass_context def init( ctx: click.Context, @@ -617,8 +685,22 @@ def init( anyllm_provider: str | None, region: str | None, memory: bool, + verbose: bool, ) -> None: """Install durable Headroom integrations for supported agents.""" + if verbose: + _enable_verbose_logging() + logger.debug( + "init: global_scope=%s port=%s backend=%s anyllm_provider=%s region=%s memory=%s " + "invoked_subcommand=%s", + global_scope, + port, + backend, + anyllm_provider, + region, + memory, + ctx.invoked_subcommand, + ) if ctx.invoked_subcommand is not None: ctx.obj = { "global_scope": global_scope, @@ -627,12 +709,15 @@ def init( "anyllm_provider": anyllm_provider, "region": region, "memory": memory, + "verbose": verbose, } return targets = detect_init_targets(global_scope) if not targets: + logger.debug("init: detect_init_targets returned empty; exiting with guided error") raise click.ClickException(_format_empty_detection_error(global_scope)) + logger.debug("init: detected targets=%s", targets) _run_init_targets( targets=targets, global_scope=global_scope, diff --git a/tests/test_cli/test_init_cli.py b/tests/test_cli/test_init_cli.py index 70465b93a..df1d1a292 100644 --- a/tests/test_cli/test_init_cli.py +++ b/tests/test_cli/test_init_cli.py @@ -104,6 +104,43 @@ def test_format_empty_detection_error_reports_found_paths(monkeypatch, tmp_path) assert "codex: not found" in message +def test_init_verbose_enables_debug_logging_on_stderr(monkeypatch) -> None: + """``headroom init -v`` should emit diagnostic lines to stderr.""" + + init_cli, fake_main = _load_init_module(monkeypatch) + # Make sure no agents are detected so the run exits fast without touching + # the filesystem. + monkeypatch.setattr(init_cli.shutil, "which", lambda name: None) + runner = CliRunner(mix_stderr=False) + + result = runner.invoke(fake_main, ["init", "-v", "-g"]) + + assert result.exit_code != 0 + # Click routes ClickException to stderr; debug logs also go to stderr. + assert "[headroom init]" in result.stderr + assert "detect_init_targets" in result.stderr + assert "global_scope=True" in result.stderr + # Target names should show up from the per-target which probe. + for target in ("claude", "codex", "copilot", "openclaw"): + assert target in result.stderr + + +def test_init_verbose_is_idempotent(monkeypatch) -> None: + """Calling _enable_verbose_logging repeatedly keeps one handler attached.""" + + init_cli, _ = _load_init_module(monkeypatch) + # Clear any prior handler state on the dedicated init logger. + init_cli.logger.handlers.clear() + if hasattr(init_cli.logger, init_cli._VERBOSE_HANDLER_ATTR): + delattr(init_cli.logger, init_cli._VERBOSE_HANDLER_ATTR) + + init_cli._enable_verbose_logging() + init_cli._enable_verbose_logging() + init_cli._enable_verbose_logging() + + assert len(init_cli.logger.handlers) == 1 + + def test_init_copilot_requires_global(monkeypatch) -> None: init_cli, fake_main = _load_init_module(monkeypatch) runner = CliRunner()