Skip to content

fix(server): batch OTLP log/trace inserts to kill ~30s ingest p99 (JEF-495)#124

Merged
thejefflarson merged 1 commit into
mainfrom
thejefflarson/jef-495-slow-log-ingest-p99-30s-store_logs-inserts-one-row-at-a-time
Jul 23, 2026
Merged

fix(server): batch OTLP log/trace inserts to kill ~30s ingest p99 (JEF-495)#124
thejefflarson merged 1 commit into
mainfrom
thejefflarson/jef-495-slow-log-ingest-p99-30s-store_logs-inserts-one-row-at-a-time

Conversation

@thejefflarson

Copy link
Copy Markdown
Owner

Closes JEF-495.

Problem

store_logs (and store_traces) inserted records one row at a time in a nested loop. For a large OTLP batch that's N sequential awaited round-trips, each acquiring a pool connection — driving ingest.logs p99 to ~30s (slow, error_count=0).

Fix

Decode the whole request into rows up front, then write them in chunked INSERT … SELECT * FROM unnest($1::type[], …) statements — parallel per-column arrays, all values bound (runtime sqlx, no interpolation).

Before → after round-trips: N (one awaited INSERT per record, each grabbing a connection) → ceil(N / 5000) (one execute per chunk). A representative single-request batch now writes in one round-trip instead of N, so ingest latency drops to sub-second.

Batch-failure semantics (decision)

A shared write_chunked helper drives both paths. On a chunk error it falls back to per-row inserts for that chunk, so a single bad row can't silently drop the whole batch — only rows that still fail are logged and counted in selfmon::DROP_INSERT, preserving the exact per-row drop accounting the old loop had. A clean batch counts every attempted row (matching the old loop, where an ON CONFLICT no-op still succeeded and still counted).

JEF-496 hook

Each insert_* is exactly one isolatable execute per call (per chunk, and per row on the fallback path), with a comment noting JEF-496 will wrap that whole-batch write in read-only-failover retry. Retry itself is not implemented here.

Unchanged behavior

  • Stored columns/values are identical (trace_id/span_id/service/attrs/body/severity/time/…).
  • Spans keep ON CONFLICT (trace_id, span_id) DO NOTHING, which also dedupes intra-batch duplicates (verified: no "affect row a second time" error — that's DO UPDATE only).
  • The metrics path was already batched; left untouched (out of scope).

Tests

server/tests/smoke.rs:

  • ingest_a_log_batch_persists_every_row_in_one_call — one request of 250 records; asserts all 250 rows persist with identical values and DROP_INSERT is untouched.
  • ingest_a_span_batch_persists_and_dedupes_in_one_call — one request of 100 distinct spans + an intra-batch duplicate; asserts 100 rows persist and the duplicate is deduped.

Checks

  • cargo fmt --check — clean
  • cargo clippy --all-targets -- -D warnings — clean
  • cargo test --locked — 44 lib + 56 smoke tests pass (against a local Postgres)

🤖 Generated with Claude Code

https://claude.ai/code/session_01JbrmfzHsTMMzPaSrUkZgWo

…F-495)

store_logs and store_traces inserted one row at a time in a nested loop,
so a large OTLP batch was N sequential awaited round-trips, each acquiring
a pool connection — driving ingest.logs p99 to ~30s.

Decode the whole request into rows, then write them in chunked
INSERT ... SELECT * FROM unnest($1::type[], ...) statements (all values
bound, no interpolation), collapsing N round-trips into O(chunks). A
shared write_chunked helper drives both paths; on a chunk error it falls
back to per-row inserts so a single bad row can't drop the whole batch,
keeping DROP_INSERT accounting accurate. Each insert is one isolatable
execute so JEF-496 can wrap it in read-only-failover retry.

Spans keep ON CONFLICT (trace_id, span_id) DO NOTHING, which dedupes
intra-batch duplicates too. Stored columns/values are unchanged.

Tests: smoke.rs ingests a 250-record log batch and a 100-span trace
batch (with an intra-batch duplicate) in one call each, asserting every
row persists with identical values and DROP_INSERT is untouched.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01JbrmfzHsTMMzPaSrUkZgWo
@thejefflarson
thejefflarson merged commit 9bc40d3 into main Jul 23, 2026
4 checks passed
@thejefflarson
thejefflarson deleted the thejefflarson/jef-495-slow-log-ingest-p99-30s-store_logs-inserts-one-row-at-a-time branch July 23, 2026 04:33
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant