Trace ingestion bottleneck: sequential per-trace upsert bypasses the async buffer (~15 spans/s)

[Polliog]

Summary

Trace ingestion is roughly three orders of magnitude slower than log ingestion on the same stack. A benchmark run on an 8 vCPU / 16 GiB VPS with the default Docker Compose profile accepted 1 million logs in about 2 minutes (~8,300 logs/s) but only 5,000 spans in about 5.5 minutes, i.e. ~15 spans/s. Extrapolated, 1 million spans would take 18 to 19 hours.

The runtime is not the cause. Reading the code, the bottleneck is the per-trace aggregation write in tracesService.ingestSpans, which is sequential, unbatched, and deliberately excluded from the async buffer.

Root cause

packages/backend/src/modules/traces/service.ts:187-201 writes one trace summary per iteration, awaiting each one:

for (const [, trace] of traces) {
  await reservoir.upsertTrace({ ... });
}

Three problems compound here:

1. N sequential round trips per request. Reservoir exposes only a single-record upsertTrace(trace) (packages/reservoir/src/core/reservoir-interface.ts:79); there is no batch variant. An OTLP export carrying spans for N distinct traces costs N serial database round trips, all on the request path, all before the HTTP response is sent.

2. The async buffer does not cover this path. ReservoirBuffered.ingestSpans enqueues to the Redis stream and returns (packages/reservoir/src/buffered/reservoir-buffered.ts:70-84), but upsertTrace is a straight pass-through to the inner engine (reservoir-buffered.ts:117). The buffer flush consumer in packages/backend/src/database/reservoir.ts:62-70 re-ingests logs, spans and metrics, and never touches trace aggregates. So enabling RESERVOIR_BUFFER_ENABLED=true speeds up the span rows and leaves the trace rows fully synchronous. That asymmetry is exactly what the benchmark measured.

3. The per-engine cost of one upsert is high, and highest on ClickHouse. ClickHouseEngine.upsertTrace (packages/reservoir/src/engines/clickhouse/clickhouse-engine.ts:909) runs an aggregate SELECT count(), min(start_time), max(end_time) ... FROM spans WHERE trace_id = ... followed by a single-row INSERT into a ReplacingMergeTree. That is two round trips per trace, one of them a scan, plus one new part per trace for the merge scheduler to clean up. Single-row inserts are the canonical ClickHouse anti-pattern. Timescale (timescale-engine.ts:658) is a single ON CONFLICT upsert and Mongo (mongodb-engine.ts:622) is a two-op bulkWrite, so both are cheaper per call, but still one round trip per trace.

Secondary finding: likely correctness issue on ClickHouse with the buffer enabled

The ClickHouse implementation documents its own precondition: "spans are always inserted before the upsert, so whichever upsert runs last writes the correct totals".

That precondition does not hold when RESERVOIR_BUFFER_ENABLED=true. ingestSpans returns after enqueueing to Redis, so when the for loop reaches upsertTrace the spans are usually not yet in the spans table. The aggregate then sees zero (or a partially flushed subset of) spans, falls back to the payload counts on the first batch, and on later batches for the same trace recomputes totals from whatever happens to have been flushed at that instant. Since ReplacingMergeTree keeps the last written row, span_count, start_time, end_time and error can end up wrong, and can move non-monotonically.

There is a startup warning against combining the buffer with non-Timescale engines (database/reservoir.ts:79-87), but it is framed as a latency regression, not as a correctness constraint. This needs verifying against a live ClickHouse instance before we treat it as confirmed.

Impact

• OTLP trace ingestion is unusable at any realistic collector volume. A single OTel Collector batch processor exporting a few hundred traces will block the request for hundreds of round trips.
• The async buffer, which is the documented answer to ingestion pressure, provides no relief for traces.
• On ClickHouse deployments the write amplification also degrades the engine over time through part accumulation.
• Users hitting this will observe OTLP export timeouts and collector-side retries, which amplify the load further.

Proposed direction

Not a plan yet, listing the options for discussion:

1. Add a batch upsert to the reservoir interface (upsertTraces(traces: TraceRecord[])) implemented on all three engines: multi-row INSERT ... ON CONFLICT on Timescale, a single multi-row INSERT on ClickHouse, one bulkWrite on Mongo. This alone collapses N round trips into 1 and is the smallest change with the largest effect. Default implementation on the base engine can loop, so no engine is left behind.
2. Route trace aggregates through the buffer as a fourth record kind, so the flush consumer performs the upsert after the spans have landed. This fixes the ClickHouse ordering precondition rather than working around it, and moves the work off the request path.
3. Reconsider the ClickHouse read-then-write. If (2) lands, the aggregate can be recomputed once per flush batch instead of once per trace, or replaced with an AggregatingMergeTree / materialized view over spans so the summary is maintained by the engine.
4. Add a trace-ingestion case to the load-test suite so this is caught by CI rather than by a one-off benchmark.

Whatever we pick must work on all three engines, per the multi-engine rule.

Reproduction

• Stack: default docker/docker-compose.yml profile (TimescaleDB, Redis, backend, worker, frontend), 8 vCPU / 16 GiB.
• RESERVOIR_BUFFER_ENABLED=true, RESERVOIR_BUFFER_TRANSPORT=redis, batches of 100.
• Drive POST /v1/traces with an OTLP payload containing many distinct trace IDs.
• Observed: ~15 spans/s sustained, while the same stack accepts ~8,300 logs/s.

Code references are against develop at 01449e7.