From a6681eac517b76b578b31ef4bc30f13a49630089 Mon Sep 17 00:00:00 2001 From: Lilly Luo Date: Wed, 8 Jul 2026 18:39:54 +0000 Subject: [PATCH 1/3] Add --verbose debug level with validation diagnostics MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Introduce a new "debug" verbosity level that surfaces step-level detail during the post-configure validation step, so users can see what validation is doing, why it's slow, and why it's failing. With --verbose debug, validate_tool now prints the command being run, the env keys ucode injects (keys only, never token values), the timeout, the exit code and elapsed time, and — on failure — the raw subprocess output. The spinner is skipped in debug mode so these per-step lines aren't clobbered by the animation. Co-authored-by: Isaac --- src/ucode/agents/__init__.py | 77 +++++++++++++++++++++++++++--------- src/ucode/cli.py | 25 ++++++++---- src/ucode/ui.py | 14 ++++++- tests/test_agents_init.py | 53 +++++++++++++++++++++++++ 4 files changed, 143 insertions(+), 26 deletions(-) diff --git a/src/ucode/agents/__init__.py b/src/ucode/agents/__init__.py index f44b91b..f8b4ee7 100644 --- a/src/ucode/agents/__init__.py +++ b/src/ucode/agents/__init__.py @@ -13,8 +13,10 @@ from __future__ import annotations import json +import os import shutil import subprocess +import time from ucode.config_io import ToolSpec from ucode.databricks import ( @@ -28,7 +30,9 @@ from ucode.telemetry import agent_version from ucode.ui import ( console, + is_debug_verbosity, is_low_verbosity, + print_debug, print_err, print_note, print_section, @@ -453,7 +457,13 @@ def ensure_provider_state(tool: str) -> dict: def validate_tool(tool: str) -> tuple[bool, str]: - """Invoke a tool with a simple prompt to verify it works. Returns (ok, error_msg).""" + """Invoke a tool with a simple prompt to verify it works. Returns (ok, error_msg). + + At debug verbosity (``--verbose debug``) prints the command being run, any + validation env vars supplied, elapsed time, and — on failure — the raw + subprocess output, so the user can see what validation is doing, why it is + slow, and why it failed. + """ spec = TOOL_SPECS[tool] binary = spec["binary"] module = _MODULES[tool] @@ -462,32 +472,56 @@ def validate_tool(tool: str) -> tuple[bool, str]: if hasattr(module, "validate_env"): try: env = module.validate_env(load_state()) - except RuntimeError: + except RuntimeError as exc: env = None + print_debug(f"validate_env unavailable, running without extra env: {exc}") + + if is_debug_verbosity(): + print_debug(f"running: {' '.join(cmd)}") + if env is not None: + # Only surface the env keys ucode injects, not the caller's full + # environment, and never the token values themselves. + injected = sorted(k for k in env if k not in os.environ or os.environ.get(k) != env[k]) + if injected: + print_debug(f"env: {', '.join(injected)}") + print_debug("timeout: 60s") + + start = time.monotonic() try: result = subprocess.run( cmd, check=False, capture_output=True, text=True, timeout=60, env=env ) - if result.returncode == 0: - return True, "" - output = (result.stderr or result.stdout or "").strip() - for line in output.splitlines(): - if "error" in line.lower() and ("message" in line.lower() or ":" in line): - msg = line.strip() - if "error_code" in msg: - try: - payload = json.loads(msg[msg.index("{") : msg.rindex("}") + 1]) - return False, payload.get("message", msg) - except (json.JSONDecodeError, ValueError): - pass - return False, msg - last_line = output.splitlines()[-1] if output else "unknown error" - return False, last_line except OSError as exc: + print_debug(f"failed to launch after {time.monotonic() - start:.1f}s: {exc}") return False, str(exc) except subprocess.TimeoutExpired: + print_debug(f"timed out after {time.monotonic() - start:.1f}s (limit 60s)") return False, "timed out" + elapsed = time.monotonic() - start + print_debug(f"exited with code {result.returncode} in {elapsed:.1f}s") + + if result.returncode == 0: + return True, "" + + output = (result.stderr or result.stdout or "").strip() + if is_debug_verbosity() and output: + print_debug("raw output:") + for line in output.splitlines(): + print_debug(f" {line}") + for line in output.splitlines(): + if "error" in line.lower() and ("message" in line.lower() or ":" in line): + msg = line.strip() + if "error_code" in msg: + try: + payload = json.loads(msg[msg.index("{") : msg.rindex("}") + 1]) + return False, payload.get("message", msg) + except (json.JSONDecodeError, ValueError): + pass + return False, msg + last_line = output.splitlines()[-1] if output else "unknown error" + return False, last_line + def provider_permission_error(tool: str, state: dict, err: str) -> str: """Rewrite the opaque gateway connection-permission failure into an @@ -511,6 +545,7 @@ def validate_all_tools(state: dict) -> None: from ucode.config_io import restore_file low_verbosity = is_low_verbosity() + debug_verbosity = is_debug_verbosity() console.print() if low_verbosity: console.print("[bold blue]Validating...[/bold blue]") @@ -528,8 +563,14 @@ def validate_all_tools(state: dict) -> None: for tool, spec in TOOL_SPECS.items(): if tool not in available_tools: continue - with spinner(f"Validating {spec['display']}..."): + # At debug verbosity the spinner would clobber the per-step debug lines, + # so print a plain status header and skip the animation instead. + if debug_verbosity: + console.print(f"[bold blue]Validating {spec['display']}...[/bold blue]") ok, err = validate_tool(tool) + else: + with spinner(f"Validating {spec['display']}..."): + ok, err = validate_tool(tool) results.append((tool, ok)) if ok: print_success(f"{spec['display']} is working") diff --git a/src/ucode/cli.py b/src/ucode/cli.py index b2f23be..bf8752b 100644 --- a/src/ucode/cli.py +++ b/src/ucode/cli.py @@ -70,6 +70,7 @@ from ucode.ui import ( console, heading, + is_debug_verbosity, print_err, print_heading, print_kv, @@ -463,6 +464,16 @@ def _use_databricks() -> dict: return state +def _validate_single_tool(tool: str, display: str) -> tuple[bool, str]: + """Run validation for one tool, skipping the spinner at debug verbosity so + its per-step diagnostics aren't clobbered by the animation.""" + if is_debug_verbosity(): + console.print(f"[bold blue]Validating {display}...[/bold blue]") + return validate_tool(tool) + with spinner(f"Validating {display}..."): + return validate_tool(tool) + + def configure_workspace_command( tool: str | None = None, selected_tools: list[str] | None = None, @@ -505,8 +516,7 @@ def configure_workspace_command( if skip_validate: print_note(f"Skipping {spec['display']} validation (--skip-validate).") return 0 - with spinner(f"Validating {spec['display']}..."): - ok, err = validate_tool(tool) + ok, err = _validate_single_tool(tool, spec["display"]) if ok: print_success(f"{spec['display']} is working") else: @@ -808,8 +818,7 @@ def _auto_configure_tool(tool: str) -> None: ) ) - with spinner(f"Validating {spec['display']}..."): - ok, err = validate_tool(tool) + ok, err = _validate_single_tool(tool, spec["display"]) if ok: print_success(f"{spec['display']} is working") else: @@ -1029,15 +1038,17 @@ def configure( typer.Option( "--verbose", help="Output verbosity: 'normal' (default) renders decorative panels; " - "'low' prints terse single-line status instead.", + "'low' prints terse single-line status instead; 'debug' additionally " + "prints step-level diagnostics during validation (command run, env " + "vars injected, elapsed time, and raw output on failure).", ), ] = "normal", ) -> None: """Configure workspace URL and AI Gateway.""" if ctx.invoked_subcommand is not None: return - if verbose not in ("normal", "low"): - print_err("--verbose must be one of: normal, low.") + if verbose not in ("normal", "low", "debug"): + print_err("--verbose must be one of: normal, low, debug.") raise typer.Exit(2) set_dry_run(dry_run) set_verbosity(verbose) diff --git a/src/ucode/ui.py b/src/ucode/ui.py index cb55797..9a06fc0 100644 --- a/src/ucode/ui.py +++ b/src/ucode/ui.py @@ -18,7 +18,9 @@ err_console = Console(stderr=True, highlight=False) # Output verbosity. "normal" (default) renders decorative panels; "low" trades -# them for terse single-line output. Set once at CLI entry via set_verbosity. +# them for terse single-line output; "debug" additionally surfaces step-level +# diagnostics (e.g. per-tool validation commands, timing, and raw output on +# failure). Set once at CLI entry via set_verbosity. _verbosity = "normal" @@ -35,6 +37,10 @@ def is_low_verbosity() -> bool: return _verbosity == "low" +def is_debug_verbosity() -> bool: + return _verbosity == "debug" + + def print_section(title: str) -> None: console.print() console.print(Panel(title, style="bold blue", expand=False)) @@ -53,6 +59,12 @@ def print_note(text: str) -> None: console.print(f"[dim]•[/dim] {text}") +def print_debug(text: str) -> None: + """Step-level diagnostic, only emitted when verbosity is 'debug'.""" + if is_debug_verbosity(): + console.print(f"[dim] ↳ {text}[/dim]") + + def print_success(message: str) -> None: console.print(f"[bold green]✔[/bold green] {message}") diff --git a/tests/test_agents_init.py b/tests/test_agents_init.py index 576fc22..92100be 100644 --- a/tests/test_agents_init.py +++ b/tests/test_agents_init.py @@ -567,3 +567,56 @@ def test_low_verbosity_omits_panels(self, monkeypatch, capsys): assert "Ready" not in out # Per-tool success line is still printed. assert "Codex is working" in out + + def test_debug_verbosity_prints_per_tool_header_without_spinner(self, monkeypatch, capsys): + import ucode.ui as ui_mod + + monkeypatch.setattr(ui_mod, "_verbosity", "debug") + out = self._run(monkeypatch, capsys) + # Debug mode prints a plain per-tool header (the spinner is skipped so + # per-step diagnostics aren't clobbered). + assert "Validating Codex..." in out + assert "Codex is working" in out + + +class TestValidateToolDiagnostics: + """`validate_tool` surfaces step-level diagnostics at debug verbosity.""" + + def _stub_subprocess(self, monkeypatch, *, returncode: int, stderr: str = "", stdout: str = ""): + def fake_run(cmd, **kwargs): + return subprocess.CompletedProcess(cmd, returncode, stdout=stdout, stderr=stderr) + + monkeypatch.setattr(agents_mod.subprocess, "run", fake_run) + + def test_debug_prints_command_and_timing_on_success(self, monkeypatch, capsys): + import ucode.ui as ui_mod + + monkeypatch.setattr(ui_mod, "_verbosity", "debug") + self._stub_subprocess(monkeypatch, returncode=0) + ok, err = agents_mod.validate_tool("codex") + out = capsys.readouterr().out + assert ok and err == "" + assert "running:" in out + assert "exited with code 0" in out + + def test_debug_prints_raw_output_on_failure(self, monkeypatch, capsys): + import ucode.ui as ui_mod + + monkeypatch.setattr(ui_mod, "_verbosity", "debug") + self._stub_subprocess(monkeypatch, returncode=1, stderr="boom: something broke") + ok, err = agents_mod.validate_tool("codex") + out = capsys.readouterr().out + assert not ok + assert "raw output:" in out + assert "boom: something broke" in out + + def test_normal_verbosity_stays_quiet(self, monkeypatch, capsys): + import ucode.ui as ui_mod + + monkeypatch.setattr(ui_mod, "_verbosity", "normal") + self._stub_subprocess(monkeypatch, returncode=1, stderr="boom: something broke") + ok, _ = agents_mod.validate_tool("codex") + out = capsys.readouterr().out + assert not ok + assert "running:" not in out + assert "raw output:" not in out From f491bd68ea517ab591c5c7e25fc8242c9de2286e Mon Sep 17 00:00:00 2001 From: Lilly Luo Date: Wed, 8 Jul 2026 19:04:23 +0000 Subject: [PATCH 2/3] Wire --verbose into launch commands so debug diagnostics work on launch MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --verbose debug previously only worked on `ucode configure`, but validation also runs on the launch path (ucode codex/claude/...). The launch commands didn't define --verbose and use ignore_unknown_options, so the flag was forwarded verbatim to the agent — the agent saw `debug` as its first positional (prompt) argument. Add a shared --verbose option to all six launch commands, consumed by ucode (via _launch_tool → set_verbosity) before auto-configure/validation runs, so `--verbose debug` surfaces validation diagnostics where the validation actually happens. Like --provider, --verbose is now a ucode-level launch flag; pass agent flags after `--` (e.g. `ucode codex -- --verbose`). Extract _validate_verbose() shared with the configure callback. Co-authored-by: Isaac --- src/ucode/cli.py | 65 +++++++++++++++++++++++++++++++++++++---------- tests/test_cli.py | 52 +++++++++++++++++++++++++++++++++++++ 2 files changed, 103 insertions(+), 14 deletions(-) diff --git a/src/ucode/cli.py b/src/ucode/cli.py index bf8752b..450ba0d 100644 --- a/src/ucode/cli.py +++ b/src/ucode/cli.py @@ -831,7 +831,20 @@ def _auto_configure_tool(tool: str) -> None: raise RuntimeError(f"{spec['display']} validation failed — config reverted.") -def _launch_tool(tool_name: str, ctx: typer.Context, provider: str | None = None) -> None: +def _validate_verbose(verbose: str) -> None: + """Validate a --verbose value, exiting with code 2 on an unknown level.""" + if verbose not in ("normal", "low", "debug"): + print_err("--verbose must be one of: normal, low, debug.") + raise typer.Exit(2) + + +def _launch_tool( + tool_name: str, ctx: typer.Context, provider: str | None = None, verbose: str = "normal" +) -> None: + _validate_verbose(verbose) + # Set verbosity before auto-configure/validation runs so `--verbose debug` + # surfaces the launch-time validation diagnostics. + set_verbosity(verbose) try: tool = normalize_tool(tool_name) existing = load_state() @@ -901,6 +914,18 @@ def _launch_tool(tool_name: str, ctx: typer.Context, provider: str | None = None raise typer.Exit(130) from None +# Shared --verbose option for the launch commands. Consumed by ucode before any +# agent passthrough (like --provider), so to forward --verbose to the agent +# itself use the `--` separator, e.g. `ucode codex -- --verbose`. +_LAUNCH_VERBOSE_OPTION = typer.Option( + "--verbose", + help="Output verbosity: 'normal' (default) renders decorative panels; " + "'low' prints terse single-line status; 'debug' additionally prints " + "step-level validation diagnostics (command run, env vars injected, " + "elapsed time, and raw output on failure). Pass agent flags after `--`.", +) + + @app.command("codex", context_settings={"allow_extra_args": True, "ignore_unknown_options": True}) def codex_cmd( ctx: typer.Context, @@ -913,9 +938,10 @@ def codex_cmd( "before any `--` separator.", ), ] = None, + verbose: Annotated[str, _LAUNCH_VERBOSE_OPTION] = "normal", ) -> None: """Launch Codex via Databricks.""" - _launch_tool("codex", ctx, provider=provider) + _launch_tool("codex", ctx, provider=provider, verbose=verbose) @app.command("claude", context_settings={"allow_extra_args": True, "ignore_unknown_options": True}) @@ -930,35 +956,48 @@ def claude_cmd( "before any `--` separator.", ), ] = None, + verbose: Annotated[str, _LAUNCH_VERBOSE_OPTION] = "normal", ) -> None: """Launch Claude Code via Databricks.""" - _launch_tool("claude", ctx, provider=provider) + _launch_tool("claude", ctx, provider=provider, verbose=verbose) @app.command("gemini", context_settings={"allow_extra_args": True, "ignore_unknown_options": True}) -def gemini_cmd(ctx: typer.Context) -> None: +def gemini_cmd( + ctx: typer.Context, + verbose: Annotated[str, _LAUNCH_VERBOSE_OPTION] = "normal", +) -> None: """Launch Gemini CLI via Databricks.""" - _launch_tool("gemini", ctx) + _launch_tool("gemini", ctx, verbose=verbose) @app.command( "opencode", context_settings={"allow_extra_args": True, "ignore_unknown_options": True} ) -def opencode_cmd(ctx: typer.Context) -> None: +def opencode_cmd( + ctx: typer.Context, + verbose: Annotated[str, _LAUNCH_VERBOSE_OPTION] = "normal", +) -> None: """Launch OpenCode via Databricks.""" - _launch_tool("opencode", ctx) + _launch_tool("opencode", ctx, verbose=verbose) @app.command("copilot", context_settings={"allow_extra_args": True, "ignore_unknown_options": True}) -def copilot_cmd(ctx: typer.Context) -> None: +def copilot_cmd( + ctx: typer.Context, + verbose: Annotated[str, _LAUNCH_VERBOSE_OPTION] = "normal", +) -> None: """Launch GitHub Copilot CLI via Databricks.""" - _launch_tool("copilot", ctx) + _launch_tool("copilot", ctx, verbose=verbose) @app.command("pi", context_settings={"allow_extra_args": True, "ignore_unknown_options": True}) -def pi_cmd(ctx: typer.Context) -> None: +def pi_cmd( + ctx: typer.Context, + verbose: Annotated[str, _LAUNCH_VERBOSE_OPTION] = "normal", +) -> None: """Launch Pi coding agent via Databricks.""" - _launch_tool("pi", ctx) + _launch_tool("pi", ctx, verbose=verbose) @configure_app.callback(invoke_without_command=True) @@ -1047,9 +1086,7 @@ def configure( """Configure workspace URL and AI Gateway.""" if ctx.invoked_subcommand is not None: return - if verbose not in ("normal", "low", "debug"): - print_err("--verbose must be one of: normal, low, debug.") - raise typer.Exit(2) + _validate_verbose(verbose) set_dry_run(dry_run) set_verbosity(verbose) prompt_optional_updates = not skip_upgrade diff --git a/tests/test_cli.py b/tests/test_cli.py index 3c5d404..5be4d80 100644 --- a/tests/test_cli.py +++ b/tests/test_cli.py @@ -486,6 +486,58 @@ def test_no_extra_args_passes_empty_list(self): assert forwarded == [] +class TestLaunchVerbose: + """`--verbose` on the launch commands is consumed by ucode (sets verbosity + before launch-time validation) rather than forwarded to the agent.""" + + @pytest.mark.parametrize("tool", TOOLS) + def test_verbose_debug_sets_verbosity_and_is_not_forwarded(self, tool): + import ucode.ui as ui_mod + + patches = _patch_launch(tool) + with ( + patches[0], + patches[1], + patches[2], + patches[3], + patches[4], + patches[5], + patches[6] as mock_launch, + patch("ucode.cli.set_verbosity") as mock_set, + ): + result = runner.invoke(app, [tool, "--verbose", "debug"]) + assert result.exit_code == 0, result.output + # ucode consumed --verbose: nothing extra is forwarded to the agent. + assert mock_launch.call_args[0][2] == [] + mock_set.assert_called_once_with("debug") + # Guard against leaking verbosity into unrelated tests. + ui_mod.set_verbosity("normal") + + def test_verbose_after_separator_is_forwarded_to_agent(self): + """`ucode codex -- --verbose debug` forwards --verbose to the agent and + leaves ucode at the default verbosity.""" + patches = _patch_launch("codex") + with ( + patches[0], + patches[1], + patches[2], + patches[3], + patches[4], + patches[5], + patches[6] as mock_launch, + patch("ucode.cli.set_verbosity") as mock_set, + ): + result = runner.invoke(app, ["codex", "--", "--verbose", "debug"]) + assert result.exit_code == 0, result.output + assert mock_launch.call_args[0][2] == ["--verbose", "debug"] + mock_set.assert_called_once_with("normal") + + def test_invalid_verbose_rejected(self): + result = runner.invoke(app, ["codex", "--verbose", "bogus"]) + assert result.exit_code == 2 + assert "--verbose must be one of" in _strip_ansi(result.output) + + class TestConfigureAgentFlag: def test_no_flag_calls_configure_all(self): with ( From dc4620f70016817887add180882964dbf0161c38 Mon Sep 17 00:00:00 2001 From: Lilly Luo Date: Wed, 8 Jul 2026 19:06:43 +0000 Subject: [PATCH 3/3] Reword validation prompt to be professional MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit "say hi in 5 words or less" is now sent to public gateways during validation. Reword to "Respond with a greeting in five words or fewer." — same terseness and word cap (keeps validation fast), but grammatical and professional. Co-authored-by: Isaac --- src/ucode/agents/claude.py | 2 +- src/ucode/agents/codex.py | 2 +- src/ucode/agents/copilot.py | 2 +- src/ucode/agents/gemini.py | 2 +- src/ucode/agents/opencode.py | 2 +- src/ucode/agents/pi.py | 2 +- tests/test_e2e.py | 2 +- 7 files changed, 7 insertions(+), 7 deletions(-) diff --git a/src/ucode/agents/claude.py b/src/ucode/agents/claude.py index 58eea4c..38b04a6 100644 --- a/src/ucode/agents/claude.py +++ b/src/ucode/agents/claude.py @@ -517,7 +517,7 @@ def validate_cmd(binary: str) -> list[str]: "--settings", str(CLAUDE_SETTINGS_PATH), "-p", - "say hi in 5 words or less", + "Respond with a greeting in five words or fewer.", "--max-turns", "1", ] diff --git a/src/ucode/agents/codex.py b/src/ucode/agents/codex.py index 2a5c657..c378277 100644 --- a/src/ucode/agents/codex.py +++ b/src/ucode/agents/codex.py @@ -406,5 +406,5 @@ def validate_cmd(binary: str) -> list[str]: CODEX_PROFILE_NAME, "exec", "--skip-git-repo-check", - "say hi in 5 words or less", + "Respond with a greeting in five words or fewer.", ] diff --git a/src/ucode/agents/copilot.py b/src/ucode/agents/copilot.py index 91192e4..9e67373 100644 --- a/src/ucode/agents/copilot.py +++ b/src/ucode/agents/copilot.py @@ -203,7 +203,7 @@ def validate_cmd(binary: str) -> list[str]: binary, *mcp_config_args(), "--prompt", - "say hi in 5 words or less", + "Respond with a greeting in five words or fewer.", "--allow-all-tools", ] diff --git a/src/ucode/agents/gemini.py b/src/ucode/agents/gemini.py index d8499e4..d9c0386 100644 --- a/src/ucode/agents/gemini.py +++ b/src/ucode/agents/gemini.py @@ -233,7 +233,7 @@ def launch(state: dict, tool_args: list[str]) -> None: def validate_cmd(binary: str) -> list[str]: - return [binary, "-p", "say hi in 5 words or less"] + return [binary, "-p", "Respond with a greeting in five words or fewer."] def validate_env(state: dict) -> dict[str, str]: diff --git a/src/ucode/agents/opencode.py b/src/ucode/agents/opencode.py index 4b614f3..448e481 100644 --- a/src/ucode/agents/opencode.py +++ b/src/ucode/agents/opencode.py @@ -290,7 +290,7 @@ def launch(state: dict, tool_args: list[str]) -> None: def validate_cmd(binary: str) -> list[str]: - return [binary, "run", "say hi in 5 words or less"] + return [binary, "run", "Respond with a greeting in five words or fewer."] def validate_env(state: dict) -> dict[str, str]: diff --git a/src/ucode/agents/pi.py b/src/ucode/agents/pi.py index e7c1760..01e97d5 100644 --- a/src/ucode/agents/pi.py +++ b/src/ucode/agents/pi.py @@ -267,7 +267,7 @@ def launch(state: dict, tool_args: list[str]) -> None: def validate_cmd(binary: str) -> list[str]: - return [binary, "--print", "say hi in 5 words or less"] + return [binary, "--print", "Respond with a greeting in five words or fewer."] def validate_env(state: dict) -> dict[str, str]: diff --git a/tests/test_e2e.py b/tests/test_e2e.py index 604452a..6e2e23b 100644 --- a/tests/test_e2e.py +++ b/tests/test_e2e.py @@ -73,7 +73,7 @@ def _run_gemini_gateway_smoke(workspace: str, model: str, token: str) -> str: url = f"{build_tool_base_url('gemini', workspace)}/v1beta/models/{model}:generateContent" payload = { "contents": [ - {"role": "user", "parts": [{"text": "say hi in 5 words or less"}]}, + {"role": "user", "parts": [{"text": "Respond with a greeting in five words or fewer."}]}, ], } req = urllib_request.Request(