feat: structured debug logging with SQLite query timings (B2_LOG)

[samkeen]

Full-kernel structured logging behind the tracing facade, opt-in via
B2_LOG (a tracing filter directive) or B2_DEBUG, rendered by the CLI as
JSON Lines on stderr — one flat object per event, ready for jq/DuckDB/
pandas reporting and plotting. stdout stays pure data.

• SQLite query timings come from SQLite itself: sqlite3_trace_v2 +
  SQLITE_TRACE_PROFILE (rusqlite "trace" feature), installed on every
  connection in db::open. Each b2::sqlite event carries the SQL template
  (?N placeholders — no bound note content or embedding blobs), numeric
  duration_us, and vm_steps/fullscan_steps for diagnosing why a query is
  slow. Statements at/over B2_SLOW_QUERY_MS (default 100) log at WARN
  with slow=true.
• Every Vault façade op runs in a b2::vault span; the CLI subscriber's
  span-close events time each op in the adapter, so b2-core stays
  wall-clock-free (determinism boundary unchanged).
• Flow milestones: b2::ingest projection/embed pass summaries and a
  per-note embed_note span (the slowest step, now plottable), b2::search
  retrieval counts (BM25/vector pool sizes).
• Inert until an adapter installs a subscriber; the core suite stays
  model-free and deterministic. Integration tests assert the JSONL
  contract end-to-end (b2-core tests/logging.rs, b2-cli tests/cli.rs).

Co-Authored-By: Claude Fable 5 noreply@anthropic.com
Claude-Session: https://claude.ai/code/session_01RPbsFi2ti6gtfWmdEu8Fhg

Summary by CodeRabbit

• New Features

  • Added opt-in structured JSON Lines logging for debugging and diagnostics.
  • Logs are written to stderr by default or to an append-only file via B2_LOG_FILE.
  • Added SQLite query timings, slow-query detection, vault operation traces, and ingestion/search progress details.
  • Added B2_SLOW_QUERY_MS to configure the slow-query threshold.

• Documentation

  • Updated the quickstart and configuration guidance for the new logging options.

[coderabbitai]

Caution

Review failed

The pull request is closed.

ℹ️ Recent review info

⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: cc70b46f-44b6-424e-b268-51b695708a3d

📥 Commits

Reviewing files that changed from the base of the PR and between aba9f26 and f0888a9.

⛔ Files ignored due to path filters (1)

• Cargo.lock is excluded by !**/*.lock

📒 Files selected for processing (11)

• CLAUDE.md
• crates/b2-cli/Cargo.toml
• crates/b2-cli/src/main.rs
• crates/b2-cli/tests/cli.rs
• crates/b2-core/Cargo.toml
• crates/b2-core/src/db.rs
• crates/b2-core/src/ingest.rs
• crates/b2-core/src/search.rs
• crates/b2-core/src/vault.rs
• crates/b2-core/tests/logging.rs
• docs/quickstart.html

---

📝 Walkthrough

Walkthrough

The PR adds opt-in JSONL tracing to the CLI, SQLite statement profiling and slow-query classification to b2-core, structured spans across vault, ingest, and search operations, documentation for logging variables, and tests covering stderr, file output, JSON fields, and append behavior.

Changes

Structured logging and instrumentation

Layer / File(s)	Summary
CLI logging configuration crates/b2-cli/Cargo.toml, crates/b2-cli/src/main.rs, CLAUDE.md, docs/quickstart.html	The CLI initializes an optional JSONL subscriber using B2_LOG, B2_DEBUG, and B2_LOG_FILE, with stderr or append-only file output documented.
SQLite statement profiling crates/b2-core/Cargo.toml, crates/b2-core/src/db.rs	SQLite profile callbacks emit SQL, duration, VM, fullscan, and slow-query fields using the B2_SLOW_QUERY_MS threshold.
Kernel operation instrumentation crates/b2-core/src/vault.rs, crates/b2-core/src/ingest.rs, crates/b2-core/src/search.rs	Vault operations gain spans, while ingest and search emit structured progress and result-count events.
Logging behavior validation crates/b2-cli/tests/cli.rs, crates/b2-core/tests/logging.rs	Tests verify JSONL output, pure stdout, file routing and append mode, SQLite timing fields, and vault span-close events.

Estimated code review effort: 3 (Moderate) | ~25 minutes

Sequence Diagram(s)

sequenceDiagram
  participant CLI
  participant Vault
  participant SQLite
  participant Sink
  CLI->>Vault: run JSON reindex or search
  Vault->>SQLite: execute profiled statements
  SQLite->>Sink: emit structured timing events
  Vault->>Sink: emit operation and pipeline spans
  Sink->>CLI: write JSONL to stderr or B2_LOG_FILE

Loading

Poem

I’m a rabbit with logs in a neat little line,
SQLite hops, timing each query just fine.
Spans bloom in the vault,
JSON streams without fault,
And stderr keeps data pure—what a design!

✨ Finishing Touches

📝 Generate docstrings

• Create stacked PR
• Commit on current branch

🧪 Generate unit tests (beta)

• Create PR with unit tests
• Commit unit tests in branch claude/debug-logging-sqlite-queries-2rxcnu

---

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

• X
• Mastodon
• Reddit
• LinkedIn

_{Comment @coderabbitai help to get the list of available commands.}