agentgrep(feat[logging]): Add agentic logs

why: Local OTel traces showed sparse Loki coverage, leaving agentic debug
loops without searchable status records for engine, TUI, MCP, and benchmark
boundaries. The logs need to remain trace-linked and content-free.

what:
- Emit structured start, completion, and failure logs for search, find, TUI,
  MCP request, and benchmark boundaries.
- Redact env, override, and config path warning extras before log records
  leave the call site.
- Cover trace linkage, redaction, and non-tool MCP request logs in telemetry
  tests.

Author: tony

scripts/benchmark.py

@@ -35,6 +35,7 @@
 import dataclasses
 import io
 import json
+import logging
 import math
 import pathlib
 import shlex
@@ -76,6 +77,8 @@
 type CommandContext = dict[str, str]
 type ProfilePayload = dict[str, object]
 
+logger = logging.getLogger("agentgrep.benchmark")
+
 
 def _telemetry_api() -> t.Any | None:
     """Return the optional project telemetry API when available."""
@@ -1570,24 +1573,74 @@ def _run_one_commit(
             prefer_hyperfine=prefer_hyperfine,
             notify=notify,
         )
+    started_at = time.monotonic()
     with telemetry.span(
         "agentgrep.benchmark.run",
         agentgrep_surface="benchmark",
         agentgrep_benchmark_commit=commit.short_sha,
+        agentgrep_benchmark_count=len(bench_names),
     ):
-        return _run_one_commit_inner(
-            commit=commit,
-            config=config,
-            bench_names=bench_names,
-            query_overrides=query_overrides,
-            runs=runs,
-            warmup=warmup,
-            no_sync=no_sync,
-            dry_run=dry_run,
-            repo=repo,
-            prefer_hyperfine=prefer_hyperfine,
-            notify=notify,
+        logger.info(
+            "benchmark run started",
+            extra={
+                "agentgrep_surface": "benchmark",
+                "agentgrep_operation": "benchmark.run",
+                "agentgrep_benchmark_commit": commit.short_sha,
+                "agentgrep_benchmark_count": len(bench_names),
+                "agentgrep_run_count": runs,
+                "agentgrep_warmup_count": warmup,
+                "agentgrep_dry_run": dry_run,
+            },
+        )
+        try:
+            measurements = _run_one_commit_inner(
+                commit=commit,
+                config=config,
+                bench_names=bench_names,
+                query_overrides=query_overrides,
+                runs=runs,
+                warmup=warmup,
+                no_sync=no_sync,
+                dry_run=dry_run,
+                repo=repo,
+                prefer_hyperfine=prefer_hyperfine,
+                notify=notify,
+            )
+        except Exception as exc:
+            duration_ms = (time.monotonic() - started_at) * 1000.0
+            telemetry.set_span_attribute("agentgrep_outcome", "error")
+            telemetry.set_span_attribute("agentgrep_error_type", type(exc).__name__)
+            telemetry.set_span_attribute("agentgrep_duration_ms", duration_ms)
+            logger.info(
+                "benchmark run failed",
+                extra={
+                    "agentgrep_surface": "benchmark",
+                    "agentgrep_operation": "benchmark.run",
+                    "agentgrep_benchmark_commit": commit.short_sha,
+                    "agentgrep_benchmark_count": len(bench_names),
+                    "agentgrep_outcome": "error",
+                    "agentgrep_error_type": type(exc).__name__,
+                    "agentgrep_duration_ms": duration_ms,
+                },
+            )
+            raise
+        duration_ms = (time.monotonic() - started_at) * 1000.0
+        telemetry.set_span_attribute("agentgrep_outcome", "ok")
+        telemetry.set_span_attribute("agentgrep_duration_ms", duration_ms)
+        telemetry.set_span_attribute("agentgrep_measurement_count", len(measurements))
+        logger.info(
+            "benchmark run completed",
+            extra={
+                "agentgrep_surface": "benchmark",
+                "agentgrep_operation": "benchmark.run",
+                "agentgrep_benchmark_commit": commit.short_sha,
+                "agentgrep_benchmark_count": len(bench_names),
+                "agentgrep_measurement_count": len(measurements),
+                "agentgrep_outcome": "ok",
+                "agentgrep_duration_ms": duration_ms,
+            },
         )
+        return measurements
 
 
 def _run_one_commit_inner(

scripts/otel_smoke.py

@@ -34,7 +34,11 @@ def main() -> int:
         ):
             logger.info(
                 "otel smoke started",
-                extra={"agentgrep_surface": "otel", "agentgrep_run_id": args.run_id},
+                extra={
+                    "agentgrep_surface": "otel",
+                    "agentgrep_operation": "otel.smoke",
+                    "agentgrep_run_id": args.run_id,
+                },
             )
             with _telemetry.span("agentgrep.otel.smoke.sqlite", agentgrep_surface="otel"):
                 connection = sqlite3.connect(
@@ -71,7 +75,11 @@ def main() -> int:
                 _telemetry.set_span_attribute("agentgrep_cpu_accumulator", accumulator)
             logger.info(
                 "otel smoke completed",
-                extra={"agentgrep_surface": "otel", "agentgrep_run_id": args.run_id},
+                extra={
+                    "agentgrep_surface": "otel",
+                    "agentgrep_operation": "otel.smoke",
+                    "agentgrep_run_id": args.run_id,
+                },
             )
     finally:
         telemetry.shutdown()

scripts/profile_engine.py

@@ -656,6 +656,7 @@ def main(argv: list[str] | None = None) -> int:
                     "profile engine completed",
                     extra={
                         "agentgrep_surface": "profile_engine",
+                        "agentgrep_operation": "profile_engine.run",
                         "agentgrep_outcome": outcome,
                         "agentgrep_exit_code": exit_code,
                     },
@@ -666,7 +667,10 @@ def main(argv: list[str] | None = None) -> int:
             assert args is not None
             logger.info(
                 "profile engine started",
-                extra={"agentgrep_surface": "profile_engine"},
+                extra={
+                    "agentgrep_surface": "profile_engine",
+                    "agentgrep_operation": "profile_engine.run",
+                },
             )
             try:
                 with _telemetry.span(
@@ -680,6 +684,7 @@ def main(argv: list[str] | None = None) -> int:
                     "profile engine failed",
                     extra={
                         "agentgrep_surface": "profile_engine",
+                        "agentgrep_operation": "profile_engine.run",
                         "agentgrep_outcome": "parse_error",
                     },
                 )
@@ -704,6 +709,7 @@ def main(argv: list[str] | None = None) -> int:
                     "profile engine failed",
                     extra={
                         "agentgrep_surface": "profile_engine",
+                        "agentgrep_operation": "profile_engine.run",
                         "agentgrep_outcome": "parse_error",
                     },
                 )
@@ -716,6 +722,7 @@ def main(argv: list[str] | None = None) -> int:
                 "profile engine completed",
                 extra={
                     "agentgrep_surface": "profile_engine",
+                    "agentgrep_operation": "profile_engine.run",
                     "agentgrep_outcome": "ok",
                     "agentgrep_exit_code": 0,
                 },