Who Verifies That the Audit Log Actually Arrived?

From the writer’s perspective, audit logs succeed all too easily. Call the logger, no exception thrown, and the application’s job is done. That doesn’t mean it was delivered.

Around audit logging in our annotation platform, we found several instances of this “thought we emitted it.”

Success Events Dropped at the Log Level

Production ran with LOG_LEVEL=warn. Audit success events were emitted at info, so Pino discarded them outright.

Meanwhile, the outbox side treated “no exception was raised” as delivered. A record counted as kept despite no record existing anywhere. An audit trail that misses successful permission operations means nothing as an audit trail.

The fix: only for successful audit events, use a child logger inheriting the request-scoped Pino instance set to level=info. The parent logger’s threshold stayed untouched. Opening normal application logs up to info in production creates volume and cost problems of another kind.

The Outbox Table and Relay

Audit event delivery now writes into an outbox table within the same transaction as the domain write; a separate relay reads and delivers them.

transaction
  -> domain table
  -> outbox table

relay
  -> 未送信の outbox 行を読む
  -> 配送する
  -> 送信済みにする

If the domain change commits, the corresponding audit event is guaranteed to be in the outbox. Conversely, if the domain change rolls back, the event disappears with it. Even if the application process crashes, the rows remain.

The relay got retries. Retries mean the same event can be delivered twice, so we deduplicate by event_id. Deliver at-least-once and make the receiver idempotent — the standard shape.

A Typed Event Contract

Event shapes are pinned down by types, with a shared fixture prepared alongside.

If structured field names drift, log-based metric filters break quietly. Alerts don’t treat “logs matching the condition stopped arriving” as anomalous, so a broken filter goes unnoticed. Hence events carry their schema as types and are strictly validated before emission.

Metrics, alerts, and Slack notifications ride the same typed-field contract. Which fields feed which metric is traceable from the code.

Export Failures Were Silent Too

One more bug of the same shape lurked around observability.

The OpenTelemetry diag logger wasn’t configured. Exports to Cloud Trace had been failing in production due to missing IAM permissions, but PERMISSION_DENIED never appeared in any log and stayed silent for days. BatchSpanProcessor export failures are reported only via OTel’s diag, so without a diag logger configured, nothing shows. Adding diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.ERROR) before sdk.start() made it detectable from Cloud Logging.

Export failures and dropped logs alike look perfectly normal from inside the application.

Separating the Verification Path

Every fix above shares the same shape.

Separate who delivers from who verifies delivery. A different process reads the outbox than performs the writes. Metrics are counted along a different path than the logger. Exporter failures land in the diag logger, not the exporter itself.

Observability machinery cannot report its own failure. Something outside has to do the checking.

For the governance side — splitting log retention and access permissions, containing output, and ratcheting down the legacy logger — I’ve covered those separately in separating production logs into lanes and reducing what may be emitted.