Add --verbose debug level with validation diagnostics

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")

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",
     ]

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.",
     ]

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",
     ]
 

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]:

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]:

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]:

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:
@@ -822,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()
@@ -892,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,
@@ -904,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})
@@ -921,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)
@@ -1029,16 +1077,16 @@ 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.")
-        raise typer.Exit(2)
+    _validate_verbose(verbose)
     set_dry_run(dry_run)
     set_verbosity(verbose)
     prompt_optional_updates = not skip_upgrade

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}")