feat(init): add -v/--verbose flag for debug diagnostics

When users hit an init regression it's opaque why: no visible state
about which agents were probed, which paths were written, which
subprocesses ran. Add a top-level flag to ``headroom init`` that routes
debug-level logging from the ``headroom.cli.init`` logger to stderr.

Instrumented decision points:

* detect_init_targets / _probe_init_targets — scope + per-target
  shutil.which result
* _write_json, _ensure_claude_hooks, _ensure_copilot_hooks,
  _ensure_codex_hooks, _ensure_codex_provider — file paths being written
* _apply_user_env — chosen scope (windows vs unix) and env-var keys
* _run_checked — each subprocess command + exit code + truncated
  stdout/stderr (useful when ``claude plugin install`` fails)
* _run_init_targets — target dispatch order and resolved profile
* top-level init callback — all flag values and invoked_subcommand

Log output goes to stderr so stdout stays clean for pipes. The handler
attached by ``_enable_verbose_logging`` is idempotent - nested
subcommand invocations don't duplicate output. The logger does not
propagate to the root logger, so enabling ``headroom init -v`` does not
affect the rest of the process.

The flag is declared on the parent Click group. Subcommands (claude,
codex, copilot, openclaw) inherit the enabled logger automatically
because the group callback runs before dispatch.

Added tests cover:

* ``init -v`` emits the expected markers to stderr, including
  ``detect_init_targets``, ``global_scope=True``, and each agent name
* ``_enable_verbose_logging`` is safe to call repeatedly (handler
  remains singular)

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
JerrettDavis 2026-04-23 15:59:57 -05:00
parent 4c062319f0
commit bb91cfe688
2 changed files with 123 additions and 1 deletions

View file

@ -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,

View file

@ -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()