Audit Logging & Trace Correlation #

Classification: Internal-Only

Covers the audit/application logging that ships with tofu-external-mcp and its bonsapi counterpart (the P7.2/P7.3 work: ENG-7196, ENG-7197) — what gets logged, how the two services’ logs join on one trace id, and how to read them when debugging. For general log search/retention (Datadog, CloudWatch, S3), see Log Management & Search.

How a trace flows across the two services #

tofu-external-mcp                          bonsapi
------------------                          -------
generateTraceContext()
  -> trace_id (32 hex), span_id (16 hex)
withLogEvent wraps the tool handler
  logs ToolCallRequest
  ... handler runs, calls bonsapi via customFetch ...
    forwards headers:
      traceparent: 00-<trace_id>-<span_id>-01
      X-TOFU-TRACE-ID: <trace_id>            -> BonsaiRootSpanBuilder parses both:
      X-Tool-Name: <tool>                       traceparent (OTel parent context)
      X-Operation-ID: <operation_id>            X-TOFU-TRACE-ID (human-readable trace_id span field)
                                                 X-Tool-Name / X-Operation-ID (span fields)
                                              BonsaiUser::from_request verifies the
                                                bearer token and, only for a genuine
                                                MCP OAuth client, calls
                                                record_authenticated_caller_service()
                                              repository (Entity/Invoice/Extraction)
                                                audit hook gates on that, builds a
                                                redacted delta, logs entity_created/
                                                updated/deleted etc.
  logs ToolCallResult (+ ToolError on failure)

Same trace_id (and its Datadog decimal form, dd.trace_id) shows up on both services’ log lines for one call — that’s the join key. tool_name/operation_id are a second, human-readable correlation path when a log line’s trace_id field is truncated or a search UI doesn’t index it.

Important: caller_service (bonsapi) is only ever set from record_authenticated_caller_service, driven by the verified bearer token’s client id — never from the client-suppliable X-Tool-Name/X-Operation-ID headers. A forged X-Tool-Name header cannot make a non-MCP request’s mutation look MCP-originated in the audit trail.

New logging fields #

Both services emit one flat, structured JSON log line per event (libs/typescript/logger’s LogEvent / bonsai-utils’s Rust counterpart in event_log.rs — field-for-field the same shape). Field names below are the actual JSON keys, not TS/Rust parameter names.

Envelope fields (top-level on every line) #

data-nested fields (vary by event; not top-level) #

Event names #

Audit-log events (event_type: audit_log) — security/compliance #

Application-log events (event_type: application_log) — operational #

Tool-call error codes (error_code, MCP only) #

A failed tool call’s error_code (libs/typescript/logger’s ErrorCode, from error-mapper.ts):

auth_failure/authz_failure tool errors are dual-written to the audit log too (bonsapi_rejected_token / bonsapi_denied_access under AuthFailureReason) — a downstream auth/authz failure is a security signal, not just an operational one.

PII redaction #

bonsapi’s audit deltas are default-deny: apps/bonsapi/src/audit/pii_redaction.rs narrows both the old and new state to a fixed per-entity_type allowlist before diffing — any field not on that list is replaced with a type-tagged placeholder ("[redacted:string]", "[redacted:object]", etc.) rather than logged. An unrecognized entity_type gets the empty allowlist (redacts everything, logs a warn! so the gap is diagnosable) — a forgotten allowlist entry fails safe.

Current allowlists: invoice (id, entity_id, status, invoice_number, total_amount, currency_id, invoice_date, created_at, updated_at), extraction (id, entity_id, type, status, created_at, updated_at), entity (id, name, created_at, updated_at, country_id). See pii_redaction.rs for the full, current list (it’s the source of truth — this doc will drift before that file does).

MCP-side request/response redaction (apps/tofu-external-mcp/src/logging/redact.ts) is a separate, per-tool opt-in allowlist (logSafeRequestFields/logSafeResponseFields) — same default-deny principle, different mechanism, since MCP tool payloads are arbitrary nested JSON rather than one flat entity record.

How to read logs by trace_id #

Local dev (mise run dev):

# Both services log to their container's stdout/stderr.
docker logs tofu-external-mcp 2>&1 | grep '<trace_id>'
docker logs bonsapi 2>&1 | grep '<trace_id>'

# Or follow both live while you make a call:
docker compose logs -f tofu-external-mcp bonsapi | grep --line-buffered '<trace_id>'

Get <trace_id> from the MCP side’s own tool_call_result line (or tool_call_request) for the call you care about — it’s present on every log line either service produces for that call.

Datadog (dev/prod): @trace_id:<trace_id> searches across both services (see Log Management & Search for the general search UI). dd.trace_id/dd.span_id are what Datadog’s own trace/log correlation UI (not just full-text search) uses to link a log line to an APM trace — bonsapi has real OTel spans; tofu-external-mcp currently has log-correlation only (no dd-trace instrumentation yet, see docs/ai/tofu-external-mcp.md).

E2E verification checklist #

Requires a running dev stack and a real Clerk login (this is an OAuth-gated MCP server — there’s no static token to script around). Re-run this after any change to tofu-external-mcp’s src/logging/ or src/tracing.ts, or bonsapi’s src/audit/ or src/model/app/logging.rs.

1. mise run dev, then confirm Claude Code is connected: claude mcp list should show tofu-external-mcp - ✓ Connected.

2. Call a mutation tool that has an audit hook — e.g. ask Claude to create_extraction for an existing entity/document page (read-only tools like get_document don’t exercise the bonsapi audit-hook path).

3. Get the call’s trace_id from tofu-external-mcp’s own tool_call_result line:

   docker logs tofu-external-mcp 2>&1 | grep '"tool_name":"create_extraction"' | tail -1
   

4. Pull both services’ lines for that trace_id and check them against the tables above:

   docker logs tofu-external-mcp 2>&1 | grep '<trace_id>'
   docker logs bonsapi 2>&1 | grep '<trace_id>'
   

   • MCP: one tool_call_request and one tool_call_result line, same trace_id/operation_id.
   • bonsapi: an extraction_created line (there’s no separate invoice_created — an AP/AR extraction’s derived invoice is covered by the same event, see the Event names table above) with the same trace_id, caller_service: "tofu-external-mcp", and data.changes containing only allowlisted fields (no page titles, contact names, etc.).
   • Both lines’ dd.trace_id decimal values match.

5. Confirm PII redaction: nothing outside each entity type’s allowlist (above) appears un-redacted in data.changes.

Breaking changes #

None in this phase — every field above is additive to the existing @bonsai/logger/bonsai-utils log envelope. Two changes from earlier phases are worth knowing if you’re comparing against old log samples: ToolCall was split into separate tool_call_request/tool_call_result events, and the envelope’s status field was renamed to result (Datadog reserves status for log-severity remapping) — both already shipped, not part of this phase.