diff --git a/.github/workflows/benchmark-hardware.yml b/.github/workflows/benchmark-hardware.yml index 3d36801ed..7ee1ef6f6 100644 --- a/.github/workflows/benchmark-hardware.yml +++ b/.github/workflows/benchmark-hardware.yml @@ -54,6 +54,14 @@ on: description: 'Read-probe fill ladder override, comma-separated row counts (default 100000,1000000,10000000,100000000). e.g. 10000000,100000000,1000000000 to probe 1B — raise duration to cover the fill, it is a hard cap on the whole run. Ignored unless scenario=read-probe.' required: false default: '' + phase2_request_rates: + description: 'Throughput Phase 2 request-rate ladder override, comma-separated req/sec (default 1,5,25,100,400). Use a finer ramp (e.g. 1,5,10,15,20,25) to pin a cliff the default 5-to-25 jump skips over — needed when the failing step kills the SUT so post-fail bisection cannot run. Ignored unless scenario=throughput.' + required: false + default: '' + read_threshold_ms: + description: 'Read-probe pass threshold override in ms (default 5000; probe timeout is threshold + 1s). Raise for diagnostic dispatches (e.g. 60000) to measure how long slow queries actually take instead of truncating at 6s. Leave empty for headline runs so the series stays comparable. Ignored unless scenario=read-probe.' + required: false + default: '' commit_results: description: 'Commit results to the dispatched ref (REPLACES the whole scenario results folder with only this dispatch''s entries). Set false for exploratory or partial-matrix runs — per-entry result JSONs are still available as the matrix jobs'' workflow artifacts.' required: true @@ -113,6 +121,8 @@ jobs: BENCH_FILL_BATCH_SIZE: ${{ github.event.inputs.fill_batch_size }} BENCH_FILL_REQUEST_RATE: ${{ github.event.inputs.fill_request_rate }} BENCH_FILL_LEVELS: ${{ github.event.inputs.fill_levels }} + BENCH_READ_THRESHOLD_MS: ${{ github.event.inputs.read_threshold_ms }} + BENCH_PHASE2_REQUEST_RATES: ${{ github.event.inputs.phase2_request_rates }} # Managed-ClickHouse credentials. Used only when modes contains # managed-ch; empty for sqlite/pgch entries (harmless — sut-bootstrap # only validates them when MODE=managed-ch). diff --git a/CLAUDE.md b/CLAUDE.md index 8cbddeb07..516e59e89 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -257,6 +257,10 @@ DUCKDB_MEMORY_LIMIT= # e.g. 4GB. Unset = DuckDB auto-tunes (~80 DUCKDB_THREADS= # e.g. 4. Unset = DuckDB auto-tunes (= cores). Cap in constrained/shared environments. DUCKDB_CHECKPOINT_THRESHOLD= # e.g. 256MB. Unset = DuckDB default (16MB). Raise under sustained ingest to reduce WAL checkpoint stalls; costs a larger WAL and longer restart replay. +# Ingest admission gate (all telemetry ingest endpoints: /api/report, /api/profiles/ingest, /api/otel/*) +INGEST_MAX_CONCURRENT= # max concurrently processed ingest requests. Unset = 2×CPU cores, min 4. Bounds ingest memory so overload sheds load with 503s instead of the process being OOM-killed (on DuckDB an OOM death is followed by a minutes-long WAL-replay stall on restart). +INGEST_ADMISSION_WAIT_SECONDS=5 # how long a request may wait for a slot before the 503 + Retry-After; 0 = reject immediately when saturated + # Notifications NOTIFICATION_POLL_SECONDS=60 # polled rule evaluation interval; minimum 5, invalid values fall back to 60 @@ -797,7 +801,7 @@ Built with `-tags telemetry_duckdb` (`CGO_ENABLED=1` required), this is an alter - **Driver:** `github.com/duckdb/duckdb-go/v2` (the official driver; marcboeker/go-duckdb is deprecated). Bundles prebuilt static libs for glibc only — **not musl/Alpine**, so the image uses Debian (`Dockerfile.duckdb`). - **Opened in** `backend/app/db/db_telemetry_duckdb.go`: telemetry path is the SQLite path with `.db` swapped for `_telemetry.duckdb`. By default DuckDB auto-tunes to the host; `DUCKDB_MEMORY_LIMIT`/`DUCKDB_THREADS`/`DUCKDB_CHECKPOINT_THRESHOLD` (passed through as DSN config options) let operators cap memory/threads so a memory-capped container doesn't read the host's RAM and OOM-kill the backend, and raise the WAL checkpoint threshold (default 16MB) so sustained Appender ingest isn't stalled by frequent checkpoints. `preserve_insertion_order=false` is always set — telemetry reads all have explicit ORDER BY, and dropping the guarantee lets DuckDB parallelize bulk loads and large scans with less memory. The read pool is bounded (`SetMaxOpenConns(duckDBMaxReadConns)`) since each DuckDB connection can use all threads + its own query memory; Appender writes use their own `DuckDBConnector.Connect()` connections and bypass that cap. Exposes `db.DuckDBConnector` (needed for the Appender). - **Writes use the Appender API**, not `INSERT` (`duckdb.NewAppenderFromConn(conn, "", table)` → `AppendRow(...)` → `Close()` flushes). Upserts still go through `ExecContext` with `ON CONFLICT`. The Appender rejects typed `*string` for nullable VARCHAR — use `nullableString()` in `backend/app/repositories/telemetry/duckdb/helpers.go` (returns untyped `nil` or the dereferenced value). -- **Write-path observability:** a row the Appender rejects is dropped rather than failing the whole frame (the SQLite backend 500s instead), so a poison row cannot wedge the SDK's retry loop. Every drop increments a per-table counter (`db.RecordTelemetryRowDropped`) and fires a rate-limited (1/min per table) `traceway.CaptureException`; Appender flush/connect failures still propagate to the request (500, SDK retries) and increment an insert-failure counter. `GET /api/health/deep` (App auth, all telemetry backends) exposes `telemetryBackend`, `droppedRows` per table, `droppedRowsTotal`, `insertFailures`, and on DuckDB an `engine` object (db/WAL file bytes, `duckdb_memory()` usage, read-pool in-use/wait stats) alongside its existing ClickHouse fields; it 503s only when the configured telemetry backend is ClickHouse and CH is unreachable (the embedded backends answer 200 with `chReachable:false`). The benchmark loadgen polls it before/after every ramp step and fails any step whose drop delta is nonzero; read-probe fills record cumulative `droppedRows` per fill level. When `MONITORING_TRACEWAY_URL` is set, `monitoring.StartTelemetryDBReporter` also emits `traceway.duckdb.*` metrics every 10s: `rows_dropped.delta`, `insert_failures.delta`, `db_size_mb`, `wal_size_mb`, `memory_used_mb`, `read_pool.in_use`, `read_pool.wait_count.delta`, `read_pool.wait_ms.delta`. The hourly retention worker issues a `CHECKPOINT` after its deletes so retention actually reclaims disk (DuckDB otherwise defers reclamation to the WAL checkpoint threshold). +- **Write-path observability:** a row the Appender rejects is dropped rather than failing the whole frame (the SQLite backend 500s instead), so a poison row cannot wedge the SDK's retry loop. Every drop increments a per-table counter (`db.RecordTelemetryRowDropped`) and fires a rate-limited (1/min per table) `traceway.CaptureException`; Appender flush/connect failures still propagate to the request (500, SDK retries) and increment an insert-failure counter. `GET /api/health/deep` (App auth, all telemetry backends) exposes `telemetryBackend`, `droppedRows` per table, `droppedRowsTotal`, `insertFailures`, `ingestRejected` (requests turned away by the ingest admission gate), and on DuckDB an `engine` object (db/WAL file bytes, `duckdb_memory()` usage, read-pool in-use/wait stats) alongside its existing ClickHouse fields; it 503s only when the configured telemetry backend is ClickHouse and CH is unreachable (the embedded backends answer 200 with `chReachable:false`). The benchmark loadgen polls it before/after every ramp step and fails any step whose drop delta is nonzero; read-probe fills record cumulative `droppedRows` per fill level. When `MONITORING_TRACEWAY_URL` is set, `monitoring.StartTelemetryDBReporter` also emits `traceway.duckdb.*` metrics every 10s: `rows_dropped.delta`, `insert_failures.delta`, `db_size_mb`, `wal_size_mb`, `memory_used_mb`, `read_pool.in_use`, `read_pool.wait_count.delta`, `read_pool.wait_ms.delta`. The hourly retention worker issues a `CHECKPOINT` after its deletes so retention actually reclaims disk (DuckDB otherwise defers reclamation to the WAL checkpoint threshold). - **`lit` placeholders:** `db.Driver` stays `lit.SQLite`, which emits `?` — DuckDB accepts these, so no separate driver was needed for reads. - **Migrations:** `backend/app/migrations/duckdb_telemetry/` (mirrors `sqlite_telemetry/` table-for-table; integer columns are `BIGINT`, JSON is `VARCHAR`, no secondary indexes since it's columnar). - **Dialect gotchas vs SQLite** (the read queries differ): native `quantile_cont(col, p)` for P50/P95/P99 instead of fetch-and-sort; `strftime('%s',col)`→`epoch(col)`; time bucketing via `time_bucket(to_seconds(N), col, TIMESTAMP '1970-01-01')` — the explicit epoch origin is required because DuckDB anchors sub-day buckets at 2000-01-03 by default, which would misalign chart buckets against the SQLite backend's epoch-floored buckets for any interval that doesn't evenly divide a day; `json_extract`→`json_extract_string`; `json_each`→`LATERAL unnest(json_keys(x))`; strict GROUP BY needs `ANY_VALUE`/`arg_max`; `SUM` returns HUGEINT (CAST to BIGINT); `CAST(.. AS REAL)`→`CAST(.. AS DOUBLE)`. diff --git a/backend/app/controllers/health_deep.go b/backend/app/controllers/health_deep.go index a18d23987..999cc5ade 100644 --- a/backend/app/controllers/health_deep.go +++ b/backend/app/controllers/health_deep.go @@ -35,6 +35,7 @@ type HealthDeepResponse struct { DroppedRows map[string]uint64 `json:"droppedRows"` DroppedRowsTotal uint64 `json:"droppedRowsTotal"` InsertFailures uint64 `json:"insertFailures"` + IngestRejected uint64 `json:"ingestRejected"` Engine *db.TelemetryEngineStats `json:"engine,omitempty"` } @@ -49,6 +50,7 @@ func (h healthDeepController) Get(c *gin.Context) { resp.DroppedRows = dropped resp.DroppedRowsTotal = droppedTotal resp.InsertFailures = insertFailures + resp.IngestRejected = db.GetIngestRejects() if engine, ok := db.GetTelemetryEngineStats(c.Request.Context()); ok { resp.Engine = &engine } diff --git a/backend/app/controllers/routes.go b/backend/app/controllers/routes.go index ac4a5fe99..894793a3e 100644 --- a/backend/app/controllers/routes.go +++ b/backend/app/controllers/routes.go @@ -35,20 +35,20 @@ type Pagination struct { func RegisterControllers(router *gin.RouterGroup) { router.OPTIONS("/report", middleware.CORSReport) - router.POST("/report", middleware.CORSReport, middleware.UseClientAuth, middleware.UseGzip, clientcontrollers.ClientController.Report) + router.POST("/report", middleware.CORSReport, middleware.UseClientAuth, middleware.IngestAdmission, middleware.UseGzip, clientcontrollers.ClientController.Report) router.OPTIONS("/profiles/ingest", middleware.CORSReport) - router.POST("/profiles/ingest", middleware.CORSReport, middleware.UseClientAuth, middleware.UseGzip, clientcontrollers.ProfileIngestController.Ingest) + router.POST("/profiles/ingest", middleware.CORSReport, middleware.UseClientAuth, middleware.IngestAdmission, middleware.UseGzip, clientcontrollers.ProfileIngestController.Ingest) otelGroup := router.Group("/otel") otelGroup.OPTIONS("/v1/traces", middleware.CORSReport) otelGroup.OPTIONS("/v1/metrics", middleware.CORSReport) otelGroup.OPTIONS("/v1/logs", middleware.CORSReport) otelGroup.OPTIONS("/v1development/profiles", middleware.CORSReport) - otelGroup.POST("/v1/traces", middleware.CORSReport, middleware.UseClientAuth, otelcontrollers.OtelController.ExportTraces) - otelGroup.POST("/v1/metrics", middleware.CORSReport, middleware.UseClientAuth, otelcontrollers.OtelController.ExportMetrics) - otelGroup.POST("/v1/logs", middleware.CORSReport, middleware.UseClientAuth, otelcontrollers.OtelController.ExportLogs) - otelGroup.POST("/v1development/profiles", middleware.CORSReport, middleware.UseClientAuth, otelcontrollers.OtelController.ExportProfiles) + otelGroup.POST("/v1/traces", middleware.CORSReport, middleware.UseClientAuth, middleware.IngestAdmission, otelcontrollers.OtelController.ExportTraces) + otelGroup.POST("/v1/metrics", middleware.CORSReport, middleware.UseClientAuth, middleware.IngestAdmission, otelcontrollers.OtelController.ExportMetrics) + otelGroup.POST("/v1/logs", middleware.CORSReport, middleware.UseClientAuth, middleware.IngestAdmission, otelcontrollers.OtelController.ExportLogs) + otelGroup.POST("/v1development/profiles", middleware.CORSReport, middleware.UseClientAuth, middleware.IngestAdmission, otelcontrollers.OtelController.ExportProfiles) router.GET("/projects", middleware.UseAppAuth, ProjectController.ListProjects) router.POST("/projects", middleware.UseAppAuth, middleware.RequireProjectAccess, ProjectController.CreateProject) diff --git a/backend/app/db/telemetry_stats.go b/backend/app/db/telemetry_stats.go index a020018f2..b980d6ddf 100644 --- a/backend/app/db/telemetry_stats.go +++ b/backend/app/db/telemetry_stats.go @@ -37,8 +37,23 @@ var ( telemetryIngestMu sync.Mutex telemetryDroppedRows = map[string]uint64{} telemetryInsertFailures uint64 + telemetryIngestRejects uint64 ) +// RecordIngestRejected counts requests turned away by the ingest admission +// gate (503). Rejects are load shedding, not data loss — the client retries. +func RecordIngestRejected() { + telemetryIngestMu.Lock() + telemetryIngestRejects++ + telemetryIngestMu.Unlock() +} + +func GetIngestRejects() uint64 { + telemetryIngestMu.Lock() + defer telemetryIngestMu.Unlock() + return telemetryIngestRejects +} + func RecordTelemetryRowDropped(table string) { telemetryIngestMu.Lock() telemetryDroppedRows[table]++ diff --git a/backend/app/middleware/ingest_admission.go b/backend/app/middleware/ingest_admission.go new file mode 100644 index 000000000..f9b9cb093 --- /dev/null +++ b/backend/app/middleware/ingest_admission.go @@ -0,0 +1,80 @@ +package middleware + +import ( + "net/http" + "os" + "runtime" + "strconv" + "sync" + "time" + + "github.com/gin-gonic/gin" + "github.com/tracewayapp/traceway/backend/app/db" +) + +// The telemetry ingest path decompresses and decodes every request body it +// accepts; without a bound, a burst of fat OTLP batches holds decoded copies +// of all of them in memory at once and the kernel OOM-kills the process +// (observed on 8 GB hosts under sustained log ingest — and on the DuckDB +// backend the death is followed by a WAL-replay stall on restart during +// which nothing answers). The gate caps concurrent ingest processing. The +// slot is acquired before the body is read, so a waiting request holds only +// a connection; a request that cannot get a slot within the wait window is +// rejected with 503 + Retry-After, which SDKs and OTLP collectors retry. +func newIngestAdmission(capacity int, wait time.Duration) gin.HandlerFunc { + slots := make(chan struct{}, capacity) + return func(c *gin.Context) { + select { + case slots <- struct{}{}: + default: + timer := time.NewTimer(wait) + defer timer.Stop() + select { + case slots <- struct{}{}: + case <-timer.C: + db.RecordIngestRejected() + c.Header("Retry-After", "2") + c.AbortWithStatusJSON(http.StatusServiceUnavailable, gin.H{"error": "ingest saturated, retry later"}) + return + case <-c.Request.Context().Done(): + c.Abort() + return + } + } + defer func() { <-slots }() + c.Next() + } +} + +func ingestCapacityFromEnv() int { + n := runtime.NumCPU() * 2 + if n < 4 { + n = 4 + } + if v := os.Getenv("INGEST_MAX_CONCURRENT"); v != "" { + if parsed, err := strconv.Atoi(v); err == nil && parsed > 0 { + n = parsed + } + } + return n +} + +func ingestWaitFromEnv() time.Duration { + if v := os.Getenv("INGEST_ADMISSION_WAIT_SECONDS"); v != "" { + if parsed, err := strconv.Atoi(v); err == nil && parsed >= 0 { + return time.Duration(parsed) * time.Second + } + } + return 5 * time.Second +} + +// The gate is built on first use, not at package init: godotenv.Load() runs +// inside run(), after package-level vars initialize, so reading the env here +// eagerly would silently ignore INGEST_* values set via a .env file. +var ingestAdmission = sync.OnceValue(func() gin.HandlerFunc { + return newIngestAdmission(ingestCapacityFromEnv(), ingestWaitFromEnv()) +}) + +func IngestAdmission(c *gin.Context) { + ingestAdmission()(c) +} diff --git a/backend/app/middleware/ingest_admission_test.go b/backend/app/middleware/ingest_admission_test.go new file mode 100644 index 000000000..d72eff15b --- /dev/null +++ b/backend/app/middleware/ingest_admission_test.go @@ -0,0 +1,93 @@ +package middleware + +import ( + "net/http" + "net/http/httptest" + "sync" + "testing" + "time" + + "github.com/gin-gonic/gin" +) + +func newAdmissionRouter(capacity int, wait time.Duration, release chan struct{}) *gin.Engine { + gin.SetMode(gin.TestMode) + r := gin.New() + r.POST("/ingest", newIngestAdmission(capacity, wait), func(c *gin.Context) { + if release != nil { + <-release + } + c.Status(http.StatusOK) + }) + return r +} + +func TestIngestAdmissionPassesUnderCapacity(t *testing.T) { + r := newAdmissionRouter(2, 50*time.Millisecond, nil) + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(http.MethodPost, "/ingest", nil)) + if w.Code != http.StatusOK { + t.Fatalf("expected 200 under capacity, got %d", w.Code) + } +} + +func TestIngestAdmissionRejectsWhenSaturated(t *testing.T) { + release := make(chan struct{}) + r := newAdmissionRouter(1, 50*time.Millisecond, release) + + var wg sync.WaitGroup + wg.Add(1) + go func() { + defer wg.Done() + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(http.MethodPost, "/ingest", nil)) + }() + + // Give the goroutine time to acquire the only slot; its handler then + // blocks on the release channel, guaranteeing saturation below. + time.Sleep(20 * time.Millisecond) + + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(http.MethodPost, "/ingest", nil)) + if w.Code != http.StatusServiceUnavailable { + t.Fatalf("expected 503 when saturated, got %d", w.Code) + } + if w.Header().Get("Retry-After") == "" { + t.Fatalf("expected Retry-After header on 503") + } + + close(release) + wg.Wait() + + w2 := httptest.NewRecorder() + r.ServeHTTP(w2, httptest.NewRequest(http.MethodPost, "/ingest", nil)) + if w2.Code != http.StatusOK { + t.Fatalf("expected 200 after release, got %d", w2.Code) + } +} + +func TestIngestAdmissionWaiterGetsSlotWhenFreed(t *testing.T) { + release := make(chan struct{}) + r := newAdmissionRouter(1, 2*time.Second, release) + + var wg sync.WaitGroup + wg.Add(1) + go func() { + defer wg.Done() + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(http.MethodPost, "/ingest", nil)) + }() + time.Sleep(20 * time.Millisecond) + + go func() { + time.Sleep(50 * time.Millisecond) + close(release) + }() + + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(http.MethodPost, "/ingest", nil)) + if w.Code != http.StatusOK { + t.Fatalf("expected waiting request to get the freed slot, got %d", w.Code) + } + wg.Wait() +} diff --git a/benchmarks/README.md b/benchmarks/README.md index f01fde8fc..13e38736d 100644 --- a/benchmarks/README.md +++ b/benchmarks/README.md @@ -46,6 +46,21 @@ the `--scenario` flag. 5 s). Results land in `benchmarks/results-probe/`. Answers "how big can the table grow before the dashboard read on this endpoint cliffs?" + Between the fill and the probes sits a **digestion gate** + (`--max-digest-wait`, default 10 m): the loadgen polls `/api/health/deep` + until the engine's db+WAL file sizes are stable across two consecutive + polls. DuckDB checkpoints its WAL asynchronously after ingest stops, and + on a small tier that checkpoint can outlast the settle window — probing + through it produces uniform timeouts on sub-millisecond queries + (a wedged engine, not query cost; observed as a nondeterministic + logs/spans "cliff" on ccx13 before the gate existed). The wait is + recorded per fill level as `digestSeconds` (with `digestTimedOut` when + the cap expired), so "how long until the box answers again after a + burst" is itself a published number. Backends without engine gauges + (SQLite, ClickHouse) pass the gate on the first poll, and the probes + use a client without the shared 30 s timeout so `--read-threshold-ms` + above 29 s actually takes effect. + The two scenarios write to sibling folders so one never overwrites the other. Each folder is wiped on each dispatch of its scenario. diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-logs-read-probe-60s-diagnostic.json b/benchmarks/blog/post-3-data/ccx13-duckdb-logs-read-probe-60s-diagnostic.json new file mode 100644 index 000000000..055f0a284 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-logs-read-probe-60s-diagnostic.json @@ -0,0 +1,133 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "logs", + "scenario": "read-probe", + "startedAt": "2026-07-21T18:19:46Z", + "endedAt": "2026-07-21T18:54:09Z", + "readProbe": { + "endpoints": [ + { + "name": "logs-severity-error", + "path": "/api/logs" + }, + { + "name": "logs-body-search", + "path": "/api/logs" + }, + { + "name": "logs-trace-id", + "path": "/api/logs" + } + ], + "readPath": "/api/logs", + "readThresholdMs": 60000, + "settleSeconds": 10, + "fillBatchSize": 8192, + "fillRequestRate": 100, + "steps": [ + { + "fillLevelTarget": 1000000, + "rowsIngested": 1622016, + "ingestSecondsElapsed": 29.849776256, + "digestSeconds": 5.007748546, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 326.083069, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 74.746933, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.219858, + "ok": true + } + ], + "medianLatencyMs": 74.746933, + "readLatencyMs": 74.746933, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 10641408, + "ingestSecondsElapsed": 169.171949097, + "digestSeconds": 5.004557737, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 1895.5242220000002, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 81.393024, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.2702590000000002, + "ok": true + } + ], + "medianLatencyMs": 81.393024, + "readLatencyMs": 81.393024, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 100581376, + "ingestSecondsElapsed": 1752.447262896, + "digestSeconds": 5.004060214, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 61010.336232999995, + "ok": false, + "error": "Post \"http://10.0.0.2/api/logs?projectId=0bc48ced-c8b4-437e-8331-6441a2008ed6\": context deadline exceeded" + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 3162.198998, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 4.405048, + "ok": true + } + ], + "medianLatencyMs": 3162.198998, + "readLatencyMs": 3162.198998, + "readOk": false, + "passed": false, + "failReason": "probe logs-severity-error failed: Post \"http://10.0.0.2/api/logs?projectId=0bc48ced-c8b4-437e-8331-6441a2008ed6\": context deadline exceeded (latency 61010ms)" + } + ], + "maxFillLevelPassed": 10000000 + }, + "maxFillLevelPassed": 10000000, + "bytesOnDisk": 13731495936, + "storedRows": 100581376, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-logs-read-probe.json b/benchmarks/blog/post-3-data/ccx13-duckdb-logs-read-probe.json new file mode 100644 index 000000000..db2ad1a75 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-logs-read-probe.json @@ -0,0 +1,133 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "logs", + "scenario": "read-probe", + "startedAt": "2026-07-21T15:53:25Z", + "endedAt": "2026-07-21T16:26:00Z", + "readProbe": { + "endpoints": [ + { + "name": "logs-severity-error", + "path": "/api/logs" + }, + { + "name": "logs-body-search", + "path": "/api/logs" + }, + { + "name": "logs-trace-id", + "path": "/api/logs" + } + ], + "readPath": "/api/logs", + "readThresholdMs": 5000, + "settleSeconds": 10, + "fillBatchSize": 8192, + "fillRequestRate": 100, + "steps": [ + { + "fillLevelTarget": 1000000, + "rowsIngested": 1695744, + "ingestSecondsElapsed": 31.215866858, + "digestSeconds": 5.006626853, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 308.118162, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 27.046025, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.01207, + "ok": true + } + ], + "medianLatencyMs": 27.046025, + "readLatencyMs": 27.046025, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 10649600, + "ingestSecondsElapsed": 160.098593092, + "digestSeconds": 5.00439974, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 2862.714559, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 85.442927, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.495565, + "ok": true + } + ], + "medianLatencyMs": 85.442927, + "readLatencyMs": 85.442927, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 100712448, + "ingestSecondsElapsed": 1705.894526407, + "digestSeconds": 5.006668129, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 6005.2135499999995, + "ok": false, + "error": "Post \"http://10.0.0.2/api/logs?projectId=0412c6e7-5f61-41f4-9244-50ece71a3b7f\": context deadline exceeded" + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 3525.108695, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.431163, + "ok": true + } + ], + "medianLatencyMs": 3525.108695, + "readLatencyMs": 3525.108695, + "readOk": false, + "passed": false, + "failReason": "probe logs-severity-error failed: Post \"http://10.0.0.2/api/logs?projectId=0412c6e7-5f61-41f4-9244-50ece71a3b7f\": context deadline exceeded (latency 6005ms)" + } + ], + "maxFillLevelPassed": 10000000 + }, + "maxFillLevelPassed": 10000000, + "bytesOnDisk": 9341763584, + "storedRows": 100712448, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-logs-throughput.json b/benchmarks/blog/post-3-data/ccx13-duckdb-logs-throughput.json new file mode 100644 index 000000000..28f3b4083 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-logs-throughput.json @@ -0,0 +1,589 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "logs", + "scenario": "throughput", + "startedAt": "2026-07-21T13:33:00Z", + "endedAt": "2026-07-21T14:09:35Z", + "phase1": { + "kind": "batch-size-ramp", + "fixedRequestRate": 5, + "steps": [ + { + "step": 1, + "batchSize": 256, + "requestRate": 5, + "attemptedItemsPerSec": 1282.0147335200115, + "actualItemsPerSec": 1282.0147335200115, + "rejected": 0, + "ingest": { + "p50": 17.26207, + "p95": 20.646595, + "p99": 24.239521, + "ok": 601, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 12288, + "walSizeBytes": 72089224, + "memoryUsedBytes": 91822080 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 1024, + "requestRate": 5, + "attemptedItemsPerSec": 3890.1021650290145, + "actualItemsPerSec": 3890.1021650290145, + "rejected": 0, + "ingest": { + "p50": 41.299574, + "p95": 47.441962, + "p99": 61.803219, + "ok": 456, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 52178944, + "walSizeBytes": 33989045, + "memoryUsedBytes": 97779712 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 4096, + "requestRate": 5, + "attemptedItemsPerSec": 15484.182970154025, + "actualItemsPerSec": 15484.182970154025, + "rejected": 0, + "ingest": { + "p50": 102.681886, + "p95": 125.63351300000001, + "p99": 992.965565, + "ok": 454, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 207630336, + "walSizeBytes": 128247991, + "memoryUsedBytes": 367263744 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 8192, + "requestRate": 5, + "attemptedItemsPerSec": 30905.12202348657, + "actualItemsPerSec": 30905.12202348657, + "rejected": 0, + "ingest": { + "p50": 131.14354, + "p95": 911.335455, + "p99": 1269.347028, + "ok": 453, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 567816192, + "walSizeBytes": 42114520, + "memoryUsedBytes": 622592000 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 60925.38489691948, + "actualItemsPerSec": 60925.38489691948, + "rejected": 0, + "ingest": { + "p50": 1652.951507, + "p95": 2388.499593, + "p99": 2624.5160250000004, + "ok": 454, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1242312704, + "walSizeBytes": 99541833, + "memoryUsedBytes": 1365245952 + }, + "passed": true + } + ], + "maxBatchSize": 16384 + }, + "phase2": { + "kind": "request-rate-ramp", + "fixedBatchSize": 16384, + "steps": [ + { + "step": 1, + "batchSize": 16384, + "requestRate": 1, + "attemptedItemsPerSec": 16520.43807786408, + "actualItemsPerSec": 16520.43807786408, + "rejected": 0, + "ingest": { + "p50": 278.388168, + "p95": 305.20088699999997, + "p99": 1170.5415050000001, + "ok": 121, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1396453376, + "walSizeBytes": 245020518, + "memoryUsedBytes": 1695809536 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 75225.16045662755, + "actualItemsPerSec": 75225.16045662755, + "rejected": 0, + "ingest": { + "p50": 2957.7459870000002, + "p95": 4785.44721, + "p99": 5096.376844, + "ok": 572, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2271227904, + "walSizeBytes": 160792262, + "memoryUsedBytes": 2467823616 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 16384, + "requestRate": 10, + "attemptedItemsPerSec": 143256.6261608713, + "actualItemsPerSec": 71497.6044799239, + "rejected": 0, + "ingest": { + "p50": 5662.247816, + "p95": 6646.563777, + "p99": 6880.767888, + "ok": 547, + "errors": 549, + "errRate": 0.5009124087591241 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3105632256, + "walSizeBytes": 130175658, + "memoryUsedBytes": 3268935680 + }, + "passed": false, + "failReason": "combined error rate 50.09% (http 50.09% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 4, + "batchSize": 16384, + "requestRate": 7.5, + "attemptedItemsPerSec": 93284.77559106264, + "actualItemsPerSec": 61884.57062352403, + "rejected": 0, + "ingest": { + "p50": 5617.176396999999, + "p95": 6592.590075, + "p99": 6779.297003, + "ok": 473, + "errors": 240, + "errRate": 0.33660589060308554 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3822071808, + "walSizeBytes": 53603346, + "memoryUsedBytes": 3742892032 + }, + "passed": false, + "failReason": "combined error rate 33.66% (http 33.66% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 6.25, + "attemptedItemsPerSec": 79448.70719746505, + "actualItemsPerSec": 64421.40238215504, + "rejected": 0, + "ingest": { + "p50": 5551.942363, + "p95": 6472.040691, + "p99": 6688.987714, + "ok": 493, + "errors": 115, + "errRate": 0.18914473684210525 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4543492096, + "walSizeBytes": 160795453, + "memoryUsedBytes": 3877896192 + }, + "passed": false, + "failReason": "combined error rate 18.91% (http 18.91% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 6, + "batchSize": 16384, + "requestRate": 5.625, + "attemptedItemsPerSec": 73095.08180662479, + "actualItemsPerSec": 64726.41412214538, + "rejected": 0, + "ingest": { + "p50": 5422.60898, + "p95": 6287.980087, + "p99": 6655.953776, + "ok": 495, + "errors": 64, + "errRate": 0.11449016100178891 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5319438336, + "walSizeBytes": 22969295, + "memoryUsedBytes": 3709337600 + }, + "passed": false, + "failReason": "combined error rate 11.45% (http 11.45% + rejected 0.00%) > 5.00% threshold" + } + ], + "maxRequestRate": 5 + }, + "phase3": { + "kind": "small-batch-rate-ramp", + "fixedBatchSize": 100, + "steps": [ + { + "step": 1, + "batchSize": 100, + "requestRate": 10, + "attemptedItemsPerSec": 1004.9267812440783, + "actualItemsPerSec": 1004.9267812440783, + "rejected": 0, + "ingest": { + "p50": 11.200266000000001, + "p95": 15.275625, + "p99": 21.741057, + "ok": 1206, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5319438336, + "walSizeBytes": 79714325, + "memoryUsedBytes": 3777495040 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 100, + "requestRate": 100, + "attemptedItemsPerSec": 9754.40861507941, + "actualItemsPerSec": 9754.40861507941, + "rejected": 0, + "ingest": { + "p50": 7.9646040000000005, + "p95": 13.466146, + "p99": 501.01513900000003, + "ok": 11706, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5419577344, + "walSizeBytes": 118481377, + "memoryUsedBytes": 3839098880 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 100, + "requestRate": 1000, + "attemptedItemsPerSec": 30093.297147245194, + "actualItemsPerSec": 30093.297147245194, + "rejected": 0, + "ingest": { + "p50": 1591.282434, + "p95": 2655.65602, + "p99": 2804.014969, + "ok": 36615, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5768228864, + "walSizeBytes": 48556398, + "memoryUsedBytes": 3740532736 + }, + "passed": false, + "failReason": "achieved 300.93 req/sec is below 70% of target 1000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 4, + "batchSize": 100, + "requestRate": 550, + "attemptedItemsPerSec": 29465.46792248597, + "actualItemsPerSec": 29433.3874878533, + "rejected": 0, + "ingest": { + "p50": 1598.8326590000001, + "p95": 2498.420931, + "p99": 5001.769138000001, + "ok": 35782, + "errors": 39, + "errRate": 0.0010887468244884285 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 6127890432, + "walSizeBytes": 195554330, + "memoryUsedBytes": 3449552896 + }, + "passed": false, + "failReason": "achieved 294.33 req/sec is below 70% of target 550.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 5, + "batchSize": 100, + "requestRate": 325, + "attemptedItemsPerSec": 30441.740603991988, + "actualItemsPerSec": 30441.740603991988, + "rejected": 0, + "ingest": { + "p50": 1571.473652, + "p95": 2564.820214, + "p99": 2755.983872, + "ok": 37011, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 6420705280, + "walSizeBytes": 143983013, + "memoryUsedBytes": 3767795712 + }, + "passed": true + }, + { + "step": 6, + "batchSize": 100, + "requestRate": 437.5, + "attemptedItemsPerSec": 30001.588816616724, + "actualItemsPerSec": 29583.963806509822, + "rejected": 0, + "ingest": { + "p50": 1548.747823, + "p95": 2618.034174, + "p99": 2686.060436, + "ok": 35986, + "errors": 508, + "errRate": 0.01392009645421165 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 6989295616, + "walSizeBytes": 44137546, + "memoryUsedBytes": 2222981120 + }, + "passed": false, + "failReason": "achieved 295.84 req/sec is below 70% of target 437.50 req/sec (workers saturated, SUT past cliff)" + } + ], + "maxRequestRate": 325 + }, + "maxSustainableItemsPerSec": 75225.16045662755, + "bytesOnDisk": 7033438208, + "storedRows": 73713480, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-read-probe-60s-diagnostic.json b/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-read-probe-60s-diagnostic.json new file mode 100644 index 000000000..03684a2d5 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-read-probe-60s-diagnostic.json @@ -0,0 +1,165 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "metrics", + "scenario": "read-probe", + "startedAt": "2026-07-21T17:11:18Z", + "endedAt": "2026-07-21T18:13:13Z", + "readProbe": { + "endpoints": [ + { + "name": "metrics-server", + "path": "/api/metrics/server" + }, + { + "name": "metrics-application", + "path": "/api/metrics/application" + }, + { + "name": "dashboard", + "path": "/api/dashboard" + } + ], + "readPath": "/api/metrics/server", + "readThresholdMs": 60000, + "settleSeconds": 10, + "fillBatchSize": 8192, + "fillRequestRate": 100, + "steps": [ + { + "fillLevelTarget": 1000000, + "rowsIngested": 2596864, + "ingestSecondsElapsed": 8.284285866, + "digestSeconds": 5.007881861, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 140.18482400000002, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 138.57956199999998, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 220.36536800000002, + "ok": true + } + ], + "medianLatencyMs": 140.18482400000002, + "readLatencyMs": 140.18482400000002, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 11550720, + "ingestSecondsElapsed": 30.158111317, + "digestSeconds": 5.007767715, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 335.28826200000003, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 381.869687, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 607.252369, + "ok": true + } + ], + "medianLatencyMs": 381.869687, + "readLatencyMs": 381.869687, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 101474304, + "ingestSecondsElapsed": 305.073646816, + "digestSeconds": 5.005782441, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 2498.3773610000003, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 2986.210888, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 4761.32388, + "ok": true + } + ], + "medianLatencyMs": 2986.210888, + "readLatencyMs": 2986.210888, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 1000000000, + "rowsIngested": 1001455616, + "ingestSecondsElapsed": 3116.321125711, + "digestSeconds": 5.004550418, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 61002.553677, + "ok": false, + "error": "Get \"http://10.0.0.2/api/metrics/server?fromDate=2026-07-20T18%3A10%3A10Z&projectId=5dd7a2f7-2701-4990-bf9b-f8617c4eee2a&toDate=2026-07-21T18%3A10%3A10Z\": context deadline exceeded" + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 61001.405750000005, + "ok": false, + "error": "Get \"http://10.0.0.2/api/metrics/application?fromDate=2026-07-20T18%3A11%3A11Z&projectId=5dd7a2f7-2701-4990-bf9b-f8617c4eee2a&toDate=2026-07-21T18%3A11%3A11Z\": context deadline exceeded" + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 61001.000224999996, + "ok": false, + "error": "Get \"http://10.0.0.2/api/dashboard?fromDate=2026-07-20T18%3A12%3A12Z&projectId=5dd7a2f7-2701-4990-bf9b-f8617c4eee2a&toDate=2026-07-21T18%3A12%3A12Z\": context deadline exceeded" + } + ], + "medianLatencyMs": 61001.405750000005, + "readLatencyMs": 61001.405750000005, + "readOk": false, + "passed": false, + "failReason": "probe metrics-server failed: Get \"http://10.0.0.2/api/metrics/server?fromDate=2026-07-20T18%3A10%3A10Z&projectId=5dd7a2f7-2701-4990-bf9b-f8617c4eee2a&toDate=2026-07-21T18%3A10%3A10Z\": context deadline exceeded (latency 61003ms)" + } + ], + "maxFillLevelPassed": 100000000 + }, + "maxFillLevelPassed": 100000000, + "bytesOnDisk": 10795061248, + "storedRows": 1001455616, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-read-probe.json b/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-read-probe.json new file mode 100644 index 000000000..52d040e94 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-read-probe.json @@ -0,0 +1,165 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "metrics", + "scenario": "read-probe", + "startedAt": "2026-07-21T14:47:29Z", + "endedAt": "2026-07-21T15:46:57Z", + "readProbe": { + "endpoints": [ + { + "name": "metrics-server", + "path": "/api/metrics/server" + }, + { + "name": "metrics-application", + "path": "/api/metrics/application" + }, + { + "name": "dashboard", + "path": "/api/dashboard" + } + ], + "readPath": "/api/metrics/server", + "readThresholdMs": 5000, + "settleSeconds": 10, + "fillBatchSize": 8192, + "fillRequestRate": 100, + "steps": [ + { + "fillLevelTarget": 1000000, + "rowsIngested": 2580480, + "ingestSecondsElapsed": 8.475577363, + "digestSeconds": 5.007948499, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 146.0298, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 135.084231, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 213.30516899999998, + "ok": true + } + ], + "medianLatencyMs": 146.0298, + "readLatencyMs": 146.0298, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 11550720, + "ingestSecondsElapsed": 30.855640677, + "digestSeconds": 5.007986705, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 343.63286500000004, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 381.574624, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 601.0998159999999, + "ok": true + } + ], + "medianLatencyMs": 381.574624, + "readLatencyMs": 381.574624, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 101490688, + "ingestSecondsElapsed": 305.46684237, + "digestSeconds": 5.003962309, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 2467.547592, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 3001.6052050000003, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 4752.907417, + "ok": true + } + ], + "medianLatencyMs": 3001.6052050000003, + "readLatencyMs": 3001.6052050000003, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 1000000000, + "rowsIngested": 1001472000, + "ingestSecondsElapsed": 3132.254449848, + "digestSeconds": 5.004906965, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 6005.238989, + "ok": false, + "error": "Get \"http://10.0.0.2/api/metrics/server?fromDate=2026-07-20T15%3A46%3A39Z&projectId=3d534138-1f31-4835-b08e-f841496cd3e9&toDate=2026-07-21T15%3A46%3A39Z\": context deadline exceeded" + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 6000.54946, + "ok": false, + "error": "Get \"http://10.0.0.2/api/metrics/application?fromDate=2026-07-20T15%3A46%3A45Z&projectId=3d534138-1f31-4835-b08e-f841496cd3e9&toDate=2026-07-21T15%3A46%3A45Z\": context deadline exceeded" + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 6005.2873389999995, + "ok": false, + "error": "Get \"http://10.0.0.2/api/dashboard?fromDate=2026-07-20T15%3A46%3A51Z&projectId=3d534138-1f31-4835-b08e-f841496cd3e9&toDate=2026-07-21T15%3A46%3A51Z\": context deadline exceeded" + } + ], + "medianLatencyMs": 6005.238989, + "readLatencyMs": 6005.238989, + "readOk": false, + "passed": false, + "failReason": "probe metrics-server failed: Get \"http://10.0.0.2/api/metrics/server?fromDate=2026-07-20T15%3A46%3A39Z&projectId=3d534138-1f31-4835-b08e-f841496cd3e9&toDate=2026-07-21T15%3A46%3A39Z\": context deadline exceeded (latency 6005ms)" + } + ], + "maxFillLevelPassed": 100000000 + }, + "maxFillLevelPassed": 100000000, + "bytesOnDisk": 10823938048, + "storedRows": 1001472000, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-throughput.json b/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-throughput.json new file mode 100644 index 000000000..d9f1788c4 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-metrics-throughput.json @@ -0,0 +1,618 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "metrics", + "scenario": "throughput", + "startedAt": "2026-07-21T12:48:00Z", + "endedAt": "2026-07-21T13:26:20Z", + "phase1": { + "kind": "batch-size-ramp", + "fixedRequestRate": 5, + "steps": [ + { + "step": 1, + "batchSize": 256, + "requestRate": 5, + "attemptedItemsPerSec": 1282.0367777269973, + "actualItemsPerSec": 1282.0367777269973, + "rejected": 0, + "ingest": { + "p50": 8.388721, + "p95": 11.190548, + "p99": 12.992066999999999, + "ok": 601, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 12288, + "walSizeBytes": 20806066, + "memoryUsedBytes": 27492352 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 1024, + "requestRate": 5, + "attemptedItemsPerSec": 3916.7726419306123, + "actualItemsPerSec": 3916.7726419306123, + "rejected": 0, + "ingest": { + "p50": 16.371666, + "p95": 18.935693, + "p99": 21.434116, + "ok": 459, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 12288, + "walSizeBytes": 84051387, + "memoryUsedBytes": 105611264 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 4096, + "requestRate": 5, + "attemptedItemsPerSec": 15425.016712180306, + "actualItemsPerSec": 15425.016712180306, + "rejected": 0, + "ingest": { + "p50": 41.498647999999996, + "p95": 47.420205, + "p99": 54.80625, + "ok": 452, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 21770240, + "walSizeBytes": 76510334, + "memoryUsedBytes": 119275520 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 8192, + "requestRate": 5, + "attemptedItemsPerSec": 30915.423404895144, + "actualItemsPerSec": 30915.423404895144, + "rejected": 0, + "ingest": { + "p50": 70.96242, + "p95": 78.35168100000001, + "p99": 253.431664, + "ok": 453, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 62926848, + "walSizeBytes": 61641784, + "memoryUsedBytes": 142082048 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 61822.383379369756, + "actualItemsPerSec": 61822.383379369756, + "rejected": 0, + "ingest": { + "p50": 99.663271, + "p95": 122.064561, + "p99": 542.562827, + "ok": 453, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 145764352, + "walSizeBytes": 28618559, + "memoryUsedBytes": 185073664 + }, + "passed": true + } + ], + "maxBatchSize": 16384 + }, + "phase2": { + "kind": "request-rate-ramp", + "fixedBatchSize": 16384, + "steps": [ + { + "step": 1, + "batchSize": 16384, + "requestRate": 1, + "attemptedItemsPerSec": 16633.34190264782, + "actualItemsPerSec": 16633.34190264782, + "rejected": 0, + "ingest": { + "p50": 105.809615, + "p95": 128.734228, + "p99": 136.536756, + "ok": 122, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 166735872, + "walSizeBytes": 39625694, + "memoryUsedBytes": 220463104 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 77912.30000410178, + "actualItemsPerSec": 77912.30000410178, + "rejected": 0, + "ingest": { + "p50": 99.736306, + "p95": 124.617478, + "p99": 566.485408, + "ok": 571, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 270282752, + "walSizeBytes": 8805716, + "memoryUsedBytes": 287047680 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 16384, + "requestRate": 10, + "attemptedItemsPerSec": 143338.27451516208, + "actualItemsPerSec": 143338.27451516208, + "rejected": 0, + "ingest": { + "p50": 61.922116, + "p95": 396.29122700000005, + "p99": 660.553282, + "ok": 1053, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 456929280, + "walSizeBytes": 8805716, + "memoryUsedBytes": 473694208 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 16384, + "requestRate": 15, + "attemptedItemsPerSec": 206136.23031869842, + "actualItemsPerSec": 206136.23031869842, + "rejected": 0, + "ingest": { + "p50": 61.575264999999995, + "p95": 620.03202, + "p99": 721.431008, + "ok": 1511, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 705703936, + "walSizeBytes": 244358405, + "memoryUsedBytes": 1006108672 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 20, + "attemptedItemsPerSec": 256340.29968471063, + "actualItemsPerSec": 254242.38196134227, + "rejected": 0, + "ingest": { + "p50": 3207.007778, + "p95": 5075.152652, + "p99": 5216.393919, + "ok": 1939, + "errors": 16, + "errRate": 0.008184143222506393 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1058287616, + "walSizeBytes": 127682774, + "memoryUsedBytes": 1217134592 + }, + "passed": true + }, + { + "step": 6, + "batchSize": 16384, + "requestRate": 25, + "attemptedItemsPerSec": 352077.7369994588, + "actualItemsPerSec": 277942.3206521025, + "rejected": 0, + "ingest": { + "p50": 5156.575400999999, + "p95": 5284.039547, + "p99": 5742.728115, + "ok": 2122, + "errors": 566, + "errRate": 0.2105654761904762 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1431318528, + "walSizeBytes": 156301325, + "memoryUsedBytes": 1625292800 + }, + "passed": false, + "failReason": "combined error rate 21.06% (http 21.06% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 7, + "batchSize": 16384, + "requestRate": 22.5, + "attemptedItemsPerSec": 320468.7140275179, + "actualItemsPerSec": 281310.5017291003, + "rejected": 0, + "ingest": { + "p50": 5137.612766, + "p95": 5270.028197000001, + "p99": 5707.497281, + "ok": 2148, + "errors": 299, + "errRate": 0.12219043727012668 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1804611584, + "walSizeBytes": 239955551, + "memoryUsedBytes": 2100297728 + }, + "passed": false, + "failReason": "combined error rate 12.22% (http 12.22% + rejected 0.00%) > 5.00% threshold" + } + ], + "maxRequestRate": 20 + }, + "phase3": { + "kind": "small-batch-rate-ramp", + "fixedBatchSize": 100, + "steps": [ + { + "step": 1, + "batchSize": 100, + "requestRate": 10, + "attemptedItemsPerSec": 1009.0901821969892, + "actualItemsPerSec": 1009.0901821969892, + "rejected": 0, + "ingest": { + "p50": 6.715396, + "p95": 8.796279, + "p99": 31.050559, + "ok": 1211, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1825058816, + "walSizeBytes": 435610, + "memoryUsedBytes": 1833172992 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 100, + "requestRate": 100, + "attemptedItemsPerSec": 9751.40723039604, + "actualItemsPerSec": 9751.40723039604, + "rejected": 0, + "ingest": { + "p50": 5.4039079999999995, + "p95": 6.915218, + "p99": 8.204802, + "ok": 11702, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1825058816, + "walSizeBytes": 159750440, + "memoryUsedBytes": 2024275968 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 100, + "requestRate": 1000, + "attemptedItemsPerSec": 53259.34480514036, + "actualItemsPerSec": 53259.34480514036, + "rejected": 0, + "ingest": { + "p50": 934.397084, + "p95": 996.504499, + "p99": 1596.77871, + "ok": 64411, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1906061312, + "walSizeBytes": 12538779, + "memoryUsedBytes": 1987575808 + }, + "passed": false, + "failReason": "achieved 532.59 req/sec is below 70% of target 1000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 4, + "batchSize": 100, + "requestRate": 550, + "attemptedItemsPerSec": 53090.9328358748, + "actualItemsPerSec": 53090.9328358748, + "rejected": 0, + "ingest": { + "p50": 947.972386, + "p95": 991.64884, + "p99": 1592.485309, + "ok": 64208, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1966616576, + "walSizeBytes": 118526270, + "memoryUsedBytes": 2230845440 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 100, + "requestRate": 775, + "attemptedItemsPerSec": 53459.12621950558, + "actualItemsPerSec": 53459.12621950558, + "rejected": 0, + "ingest": { + "p50": 941.8437349999999, + "p95": 975.135188, + "p99": 1591.7919230000002, + "ok": 64652, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2027171840, + "walSizeBytes": 230612977, + "memoryUsedBytes": 2478309376 + }, + "passed": false, + "failReason": "achieved 534.59 req/sec is below 70% of target 775.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 6, + "batchSize": 100, + "requestRate": 662.5, + "attemptedItemsPerSec": 52746.649581601785, + "actualItemsPerSec": 52746.649581601785, + "rejected": 0, + "ingest": { + "p50": 938.609297, + "p95": 980.475246, + "p99": 1612.6566, + "ok": 63780, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2119708672, + "walSizeBytes": 74851576, + "memoryUsedBytes": 2406481920 + }, + "passed": true + } + ], + "maxRequestRate": 662.5 + }, + "maxSustainableItemsPerSec": 254242.38196134227, + "bytesOnDisk": 2194571264, + "storedRows": 195695536, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-spans-read-probe-60s-diagnostic.json b/benchmarks/blog/post-3-data/ccx13-duckdb-spans-read-probe-60s-diagnostic.json new file mode 100644 index 000000000..59a0f5041 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-spans-read-probe-60s-diagnostic.json @@ -0,0 +1,127 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "spans", + "scenario": "read-probe", + "startedAt": "2026-07-21T16:37:18Z", + "endedAt": "2026-07-21T17:04:00Z", + "readProbe": { + "endpoints": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped" + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart" + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces" + } + ], + "readPath": "/api/endpoints/grouped", + "readThresholdMs": 60000, + "settleSeconds": 10, + "fillBatchSize": 8192, + "fillRequestRate": 100, + "steps": [ + { + "fillLevelTarget": 1000000, + "rowsIngested": 2211840, + "ingestSecondsElapsed": 25.030675862, + "digestSeconds": 5.005918072, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 205.227515, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 183.74937, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 2.813505, + "ok": true + } + ], + "medianLatencyMs": 183.74937, + "readLatencyMs": 183.74937, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 10838016, + "ingestSecondsElapsed": 103.850431033, + "digestSeconds": 5.005578797, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 845.7596739999999, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 759.485461, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 2.839823, + "ok": true + } + ], + "medianLatencyMs": 759.485461, + "readLatencyMs": 759.485461, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 100630528, + "ingestSecondsElapsed": 1251.663304011, + "digestSeconds": 5.005885474, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 61010.333948, + "ok": false, + "error": "Post \"http://10.0.0.2/api/endpoints/grouped?projectId=cc8e0fcf-03cb-4bad-b800-8913b1f85aa3\": context deadline exceeded" + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 61000.414962999996, + "ok": false, + "error": "Post \"http://10.0.0.2/api/endpoints/chart?projectId=cc8e0fcf-03cb-4bad-b800-8913b1f85aa3\": context deadline exceeded" + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 51954.515633, + "ok": true + } + ], + "medianLatencyMs": 61000.414962999996, + "readLatencyMs": 61000.414962999996, + "readOk": false, + "passed": false, + "failReason": "probe endpoints-grouped failed: Post \"http://10.0.0.2/api/endpoints/grouped?projectId=cc8e0fcf-03cb-4bad-b800-8913b1f85aa3\": context deadline exceeded (latency 61010ms)" + } + ], + "maxFillLevelPassed": 10000000 + }, + "maxFillLevelPassed": 10000000, + "sutContainer": {} +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-spans-read-probe.json b/benchmarks/blog/post-3-data/ccx13-duckdb-spans-read-probe.json new file mode 100644 index 000000000..16eb488a7 --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-spans-read-probe.json @@ -0,0 +1,128 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "spans", + "scenario": "read-probe", + "startedAt": "2026-07-21T14:23:14Z", + "endedAt": "2026-07-21T14:40:18Z", + "readProbe": { + "endpoints": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped" + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart" + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces" + } + ], + "readPath": "/api/endpoints/grouped", + "readThresholdMs": 5000, + "settleSeconds": 10, + "fillBatchSize": 8192, + "fillRequestRate": 100, + "steps": [ + { + "fillLevelTarget": 1000000, + "rowsIngested": 1695744, + "ingestSecondsElapsed": 16.074486227, + "digestSeconds": 5.006851318, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 169.113337, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 139.026456, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 2.492602, + "ok": true + } + ], + "medianLatencyMs": 139.026456, + "readLatencyMs": 139.026456, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 10780672, + "ingestSecondsElapsed": 83.963192231, + "digestSeconds": 5.006837973, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 939.389513, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 902.3118890000001, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 3.0820079999999996, + "ok": true + } + ], + "medianLatencyMs": 902.3118890000001, + "readLatencyMs": 902.3118890000001, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 100646912, + "ingestSecondsElapsed": 858.420307916, + "digestSeconds": 5.005910713, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 6005.285989, + "ok": false, + "error": "Post \"http://10.0.0.2/api/endpoints/grouped?projectId=d589ccbf-929d-47e7-8709-c4b57967efaa\": context deadline exceeded" + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 6002.100358, + "ok": false, + "error": "Post \"http://10.0.0.2/api/endpoints/chart?projectId=d589ccbf-929d-47e7-8709-c4b57967efaa\": context deadline exceeded" + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 6005.271328, + "ok": false, + "error": "Post \"http://10.0.0.2/api/exception-stack-traces?projectId=d589ccbf-929d-47e7-8709-c4b57967efaa\": context deadline exceeded" + } + ], + "medianLatencyMs": 6005.271328, + "readLatencyMs": 6005.271328, + "readOk": false, + "passed": false, + "failReason": "probe endpoints-grouped failed: Post \"http://10.0.0.2/api/endpoints/grouped?projectId=d589ccbf-929d-47e7-8709-c4b57967efaa\": context deadline exceeded (latency 6005ms)" + } + ], + "maxFillLevelPassed": 10000000 + }, + "maxFillLevelPassed": 10000000, + "sutContainer": {} +} diff --git a/benchmarks/blog/post-3-data/ccx13-duckdb-spans-throughput.json b/benchmarks/blog/post-3-data/ccx13-duckdb-spans-throughput.json new file mode 100644 index 000000000..c40bfa28e --- /dev/null +++ b/benchmarks/blog/post-3-data/ccx13-duckdb-spans-throughput.json @@ -0,0 +1,551 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "spans", + "scenario": "throughput", + "startedAt": "2026-07-21T12:07:22Z", + "endedAt": "2026-07-21T12:41:42Z", + "phase1": { + "kind": "batch-size-ramp", + "fixedRequestRate": 5, + "steps": [ + { + "step": 1, + "batchSize": 256, + "requestRate": 5, + "attemptedItemsPerSec": 1282.0259534142108, + "actualItemsPerSec": 1282.0259534142108, + "rejected": 0, + "ingest": { + "p50": 14.013178, + "p95": 16.96497, + "p99": 19.282500000000002, + "ok": 601, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 12288, + "walSizeBytes": 47958770, + "memoryUsedBytes": 63391744 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 1024, + "requestRate": 5, + "attemptedItemsPerSec": 3864.8327211368464, + "actualItemsPerSec": 3864.8327211368464, + "rejected": 0, + "ingest": { + "p50": 27.599517, + "p95": 31.053155, + "p99": 36.705102000000004, + "ok": 453, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 12288, + "walSizeBytes": 192159970, + "memoryUsedBytes": 242436096 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 4096, + "requestRate": 5, + "attemptedItemsPerSec": 15415.069839229409, + "actualItemsPerSec": 15415.069839229409, + "rejected": 0, + "ingest": { + "p50": 79.253023, + "p95": 89.611228, + "p99": 667.014361, + "ok": 455, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 164114432, + "memoryUsedBytes": 165937152 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 8192, + "requestRate": 5, + "attemptedItemsPerSec": 31185.415455549006, + "actualItemsPerSec": 31185.415455549006, + "rejected": 0, + "ingest": { + "p50": 109.707679, + "p95": 303.442473, + "p99": 1034.8829250000001, + "ok": 457, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 384315392, + "walSizeBytes": 132306731, + "memoryUsedBytes": 549715968 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 61868.83919864189, + "actualItemsPerSec": 61868.83919864189, + "rejected": 0, + "ingest": { + "p50": 153.437194, + "p95": 1095.361743, + "p99": 1326.792363, + "ok": 454, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 879505408, + "walSizeBytes": 106856836, + "memoryUsedBytes": 1014497280 + }, + "passed": true + } + ], + "maxBatchSize": 16384 + }, + "phase2": { + "kind": "request-rate-ramp", + "fixedBatchSize": 16384, + "steps": [ + { + "step": 1, + "batchSize": 16384, + "requestRate": 1, + "attemptedItemsPerSec": 16613.77616534193, + "actualItemsPerSec": 16613.77616534193, + "rejected": 0, + "ingest": { + "p50": 192.8409, + "p95": 214.86640500000001, + "p99": 308.191637, + "ok": 122, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 989081600, + "walSizeBytes": 208632672, + "memoryUsedBytes": 1247281152 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 77244.81427079927, + "actualItemsPerSec": 77244.81427079927, + "rejected": 0, + "ingest": { + "p50": 151.988618, + "p95": 1031.59392, + "p99": 1312.071797, + "ok": 571, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1647325184, + "memoryUsedBytes": 1649147904 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 16384, + "requestRate": 10, + "attemptedItemsPerSec": 138084.37152707088, + "actualItemsPerSec": 107833.59325107424, + "rejected": 0, + "ingest": { + "p50": 5371.09331, + "p95": 6224.11976, + "p99": 6456.579825000001, + "ok": 827, + "errors": 232, + "errRate": 0.2190745986779981 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2542022656, + "walSizeBytes": 15267121, + "memoryUsedBytes": 2566127616 + }, + "passed": false, + "failReason": "combined error rate 21.91% (http 21.91% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 4, + "batchSize": 16384, + "requestRate": 7.5, + "attemptedItemsPerSec": 95737.31828767364, + "actualItemsPerSec": 95737.31828767364, + "rejected": 0, + "ingest": { + "p50": 1167.7336220000002, + "p95": 1838.536839, + "p99": 2014.953619, + "ok": 712, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3312988160, + "memoryUsedBytes": 3314810880 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 8.75, + "attemptedItemsPerSec": 111024.5180973839, + "actualItemsPerSec": 100208.7493155965, + "rejected": 0, + "ingest": { + "p50": 5250.536638, + "p95": 5967.252186, + "p99": 6300.6231210000005, + "ok": 769, + "errors": 83, + "errRate": 0.09741784037558686 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4139003904, + "walSizeBytes": 15264471, + "memoryUsedBytes": 3702259712 + }, + "passed": false, + "failReason": "combined error rate 9.74% (http 9.74% + rejected 0.00%) > 5.00% threshold" + } + ], + "maxRequestRate": 7.5 + }, + "phase3": { + "kind": "small-batch-rate-ramp", + "fixedBatchSize": 100, + "steps": [ + { + "step": 1, + "batchSize": 100, + "requestRate": 10, + "attemptedItemsPerSec": 1007.3809777695797, + "actualItemsPerSec": 1007.3809777695797, + "rejected": 0, + "ingest": { + "p50": 9.489968999999999, + "p95": 12.72621, + "p99": 18.979889999999997, + "ok": 1209, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4139003904, + "walSizeBytes": 53169103, + "memoryUsedBytes": 3749183488 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 100, + "requestRate": 100, + "attemptedItemsPerSec": 9754.603111536819, + "actualItemsPerSec": 9754.603111536819, + "rejected": 0, + "ingest": { + "p50": 7.615841, + "p95": 10.681462, + "p99": 26.597788, + "ok": 11706, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4192743424, + "walSizeBytes": 164160818, + "memoryUsedBytes": 3890741248 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 100, + "requestRate": 1000, + "attemptedItemsPerSec": 36913.98112451267, + "actualItemsPerSec": 36913.98112451267, + "rejected": 0, + "ingest": { + "p50": 1295.6169630000002, + "p95": 2293.325409, + "p99": 2537.409309, + "ok": 44772, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4514656256, + "walSizeBytes": 31479949, + "memoryUsedBytes": 3708551168 + }, + "passed": false, + "failReason": "achieved 369.14 req/sec is below 70% of target 1000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 4, + "batchSize": 100, + "requestRate": 550, + "attemptedItemsPerSec": 36555.4153674194, + "actualItemsPerSec": 36555.4153674194, + "rejected": 0, + "ingest": { + "p50": 1337.9296969999998, + "p95": 2166.9471169999997, + "p99": 2562.0238520000003, + "ok": 44356, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4783616000, + "walSizeBytes": 141747760, + "memoryUsedBytes": 3862429696 + }, + "passed": false, + "failReason": "achieved 365.55 req/sec is below 70% of target 550.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 5, + "batchSize": 100, + "requestRate": 325, + "attemptedItemsPerSec": 32769.56646378661, + "actualItemsPerSec": 32769.56646378661, + "rejected": 0, + "ingest": { + "p50": 6.744288999999999, + "p95": 903.700262, + "p99": 1278.921382, + "ok": 39326, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5053886464, + "walSizeBytes": 94589409, + "memoryUsedBytes": 3805806592 + }, + "passed": true + }, + { + "step": 6, + "batchSize": 100, + "requestRate": 437.5, + "attemptedItemsPerSec": 36576.94340054637, + "actualItemsPerSec": 36576.94340054637, + "rejected": 0, + "ingest": { + "p50": 1315.54054, + "p95": 2160.389081, + "p99": 2386.859315, + "ok": 44375, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5321273344, + "walSizeBytes": 205617910, + "memoryUsedBytes": 3943956480 + }, + "passed": true + } + ], + "maxRequestRate": 437.5 + }, + "maxSustainableItemsPerSec": 95737.31828767364, + "bytesOnDisk": 5526900736, + "storedRows": 81406272, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/loadgen/ingest.go b/benchmarks/loadgen/ingest.go index 0bf918f25..142ac2452 100644 --- a/benchmarks/loadgen/ingest.go +++ b/benchmarks/loadgen/ingest.go @@ -22,6 +22,7 @@ type ingester struct { requestRate atomic.Int64 // requests/sec, scaled by 1e3 so we keep fractional resolution attemptedItems atomic.Int64 rejectedItems atomic.Int64 + okItems atomic.Int64 // items in 2xx responses minus PartialSuccess rejects — rows that actually landed // rng pool: each worker grabs one to avoid contending on the global source rngPool sync.Pool @@ -105,6 +106,14 @@ func (i *ingester) SnapshotAndResetItems() (attempted, rejected int64) { return } +// SnapshotAndResetOkItems returns items confirmed by 2xx responses (minus +// OTLP PartialSuccess rejects) since the last call. The read-probe fill +// tracks this instead of attempted items so admission-gate 503s and other +// HTTP failures don't count phantom rows toward a fill target. +func (i *ingester) SnapshotAndResetOkItems() int64 { + return i.okItems.Swap(0) +} + // Start launches the worker pool sized for the current request rate. The // passed ctx is used directly for HTTP requests so in-flight requests survive // across step boundaries; the limiter loop uses a derived acceptCtx that @@ -129,7 +138,7 @@ func (i *ingester) Start(ctx context.Context) { batchSize := int(i.batchSize.Load()) // HTTP uses the parent ctx (not acceptCtx) so requests in // flight when StopAccepting fires aren't canceled mid-flight. - sendOneOTLP(ctx, i.client, i.cfg, i.sender, rng, batchSize, i.stats, &i.attemptedItems, &i.rejectedItems) + sendOneOTLP(ctx, i.client, i.cfg, i.sender, rng, batchSize, i.stats, &i.attemptedItems, &i.rejectedItems, &i.okItems) } }() } diff --git a/benchmarks/loadgen/main.go b/benchmarks/loadgen/main.go index 857f5efd2..4fd4fdc92 100644 --- a/benchmarks/loadgen/main.go +++ b/benchmarks/loadgen/main.go @@ -40,6 +40,7 @@ type config struct { fillLevels []int64 readThresholdMs int settleSeconds time.Duration + maxDigestWait time.Duration fillBatchSize int fillRequestRate float64 reportOut string @@ -81,6 +82,7 @@ func main() { flag.StringVar(&fillLevelsStr, "fill-levels", "100000,1000000,10000000,100000000", "Comma-separated row counts to fill before probing a read (read-probe scenario)") flag.IntVar(&cfg.readThresholdMs, "read-threshold-ms", 5000, "Read latency threshold in ms; step fails if a probe exceeds it (read-probe scenario)") flag.DurationVar(&cfg.settleSeconds, "settle-seconds", 10*time.Second, "Wait between finishing ingest and probing the read (read-probe scenario)") + flag.DurationVar(&cfg.maxDigestWait, "max-digest-wait", 10*time.Minute, "After each read-probe fill, poll /api/health/deep until the engine's db+WAL file sizes are stable across two consecutive polls (DuckDB checkpoints the WAL after ingest stops; probing mid-checkpoint measures a wedged engine, not query cost). Cap on that wait; 0 disables. No-op on backends without engine gauges (SQLite, ClickHouse).") flag.IntVar(&cfg.fillBatchSize, "fill-batch-size", 8192, "OTLP batch size used during the fill phase (read-probe scenario)") flag.Float64Var(&cfg.fillRequestRate, "fill-request-rate", 100, "OTLP request rate (req/sec) during the fill phase (read-probe scenario)") flag.StringVar(&cfg.reportOut, "report-out", "", "Path to write JSON results (required)") diff --git a/benchmarks/loadgen/otlp_common.go b/benchmarks/loadgen/otlp_common.go index a2a2d9e15..ed2e9a75d 100644 --- a/benchmarks/loadgen/otlp_common.go +++ b/benchmarks/loadgen/otlp_common.go @@ -67,6 +67,7 @@ func sendOneOTLP( stats *latencyTracker, attemptedItems *atomic.Int64, rejectedItems *atomic.Int64, + okItems *atomic.Int64, ) { body, err := sender.BuildBody(rng, batchSize) if err != nil { @@ -104,8 +105,10 @@ func sendOneOTLP( return } - if rej := sender.ParseRejected(respBody); rej > 0 { + rej := sender.ParseRejected(respBody) + if rej > 0 { rejectedItems.Add(int64(rej)) } + okItems.Add(int64(batchSize) - int64(rej)) stats.Record(elapsed.Seconds()*1000, nil) } diff --git a/benchmarks/loadgen/read_probe.go b/benchmarks/loadgen/read_probe.go index aa2cde4f8..e34cffc5e 100644 --- a/benchmarks/loadgen/read_probe.go +++ b/benchmarks/loadgen/read_probe.go @@ -27,7 +27,14 @@ type readProbeStep struct { // DroppedRows is cumulative since scenario start, mirroring RowsIngested. // Nonzero means the SUT silently discarded rows during fill, so the true // table size is RowsIngested minus DroppedRows. - DroppedRows int64 `json:"droppedRows,omitempty"` + DroppedRows int64 `json:"droppedRows,omitempty"` + // DigestSeconds is how long the SUT's engine needed after the fill before + // its db+WAL file sizes went stable (the WAL-checkpoint gate). Probes run + // after this wait, so latencies measure steady-state query cost, not a + // mid-checkpoint wedge. DigestTimedOut means the cap expired first and + // the probes ran against a possibly still-digesting engine. + DigestSeconds float64 `json:"digestSeconds,omitempty"` + DigestTimedOut bool `json:"digestTimedOut,omitempty"` Probes []endpointProbeResult `json:"probes"` MedianLatencyMs float64 `json:"medianLatencyMs"` // Back-compat: equals MedianLatencyMs and AND-of-all-probe-Ok respectively. @@ -82,12 +89,18 @@ func runReadProbe(ctx context.Context, cfg config, ing *ingester, ingestStats *l res.ReadPath = endpoints[0].Path } + // The shared client carries a 30s Timeout that would silently cap probes + // below a raised --read-threshold-ms; probes get their own client so the + // per-probe context (threshold + 1s) is the only deadline. + probeClient := &http.Client{Transport: client.Transport} + ing.SetBatchSize(cfg.fillBatchSize) ing.SetRequestRate(cfg.fillRequestRate) // Reset the ingester counters before starting so totalIngested reflects // only what this scenario sent. ing.SnapshotAndResetItems() + ing.SnapshotAndResetOkItems() ingestStats.SnapshotAndReset() _, sutStatsBase := fetchDeepHealth(ctx, cfg, client) @@ -110,8 +123,7 @@ func runReadProbe(ctx context.Context, cfg config, ing *ingester, ingestStats *l step.RowsIngested = totalIngested // Drain whatever bumped between Stop and Snapshot. - extraAttempted, _ := ing.SnapshotAndResetItems() - totalIngested += extraAttempted + totalIngested += ing.SnapshotAndResetOkItems() step.RowsIngested = totalIngested if sutStatsBase.Reachable { @@ -123,8 +135,17 @@ func runReadProbe(ctx context.Context, cfg config, ing *ingester, ingestStats *l } } - fmt.Fprintf(stderrPrefix(), "read-probe fill=%d rows reached in %.1fs (signal=%s) — settling %ds\n", - step.RowsIngested, step.IngestSecondsElapsed, cfg.signal, res.SettleSeconds) + step.DigestSeconds, step.DigestTimedOut = waitForIngestDigestion(ctx, cfg, client.Transport) + if step.DigestTimedOut { + fmt.Fprintf(stderrPrefix(), "read-probe: engine still digesting after %.0fs cap — probing anyway\n", step.DigestSeconds) + } + // ClickHouse's post-ingest work is merges rather than a WAL + // checkpoint; give it the same courtesy before probing. Skips + // instantly on backends where CH isn't reachable. + waitForMergesIdle(ctx, cfg, client, fmt.Sprintf("fill %d -> probe", target)) + + fmt.Fprintf(stderrPrefix(), "read-probe fill=%d rows reached in %.1fs (signal=%s) — digested in %.1fs, settling %ds\n", + step.RowsIngested, step.IngestSecondsElapsed, cfg.signal, step.DigestSeconds, res.SettleSeconds) select { case <-time.After(cfg.settleSeconds): @@ -142,7 +163,7 @@ func runReadProbe(ctx context.Context, cfg config, ing *ingester, ingestStats *l allOk := true latencies := make([]float64, 0, len(endpoints)) for _, ep := range endpoints { - latency, err := probeReadEndpoint(ctx, client, cfg, ep) + latency, err := probeReadEndpoint(ctx, probeClient, cfg, ep) pr := endpointProbeResult{ Name: ep.Name, Path: ep.Path, @@ -195,10 +216,12 @@ func runReadProbe(ctx context.Context, cfg config, ing *ingester, ingestStats *l return res } -// pollFillProgress drains attempted-item counters from the ingester until the -// target is reached or the context cancels. Sub-second polling keeps overshoot -// small (at fill-batch=8192 × 100 req/s the loadgen sends ~800k items/sec, so -// 200ms granularity overshoots by ≤160k items — negligible at 100M fill). +// pollFillProgress drains confirmed-item counters from the ingester until the +// target is reached or the context cancels. Counting only 2xx-confirmed items +// (not attempts) keeps the fill honest when the SUT sheds load with 503s. +// Sub-second polling keeps overshoot small (at fill-batch=8192 × 100 req/s +// the loadgen sends ~800k items/sec, so 200ms granularity overshoots by +// ≤160k items — negligible at 100M fill). func pollFillProgress(ctx context.Context, ing *ingester, totalIngested *int64, target int64) { tick := time.NewTicker(200 * time.Millisecond) defer tick.Stop() @@ -207,8 +230,7 @@ func pollFillProgress(ctx context.Context, ing *ingester, totalIngested *int64, case <-ctx.Done(): return case <-tick.C: - attempted, _ := ing.SnapshotAndResetItems() - *totalIngested += attempted + *totalIngested += ing.SnapshotAndResetOkItems() } } } @@ -261,6 +283,53 @@ func endpointSetForSignal(signal string) []readProbeEndpoint { return nil } +// waitForIngestDigestion blocks until the SUT's storage engine has absorbed +// the fill burst, or cfg.maxDigestWait expires. DuckDB checkpoints the WAL +// asynchronously after ingest stops; probing mid-checkpoint on a small box +// measures a wedged engine, not query cost — the symptom is sub-millisecond +// queries timing out uniformly. /api/health/deep is the canary: on DuckDB it +// executes real engine queries, so it only answers promptly when a dashboard +// query would too. "Digested" means two consecutive successful polls, 5s +// apart, reporting identical db+WAL file sizes. Backends without engine +// gauges (SQLite, ClickHouse) return on the first successful poll, keeping +// their timing behavior identical to before this gate existed. Returns the +// seconds waited and whether the cap expired first. +func waitForIngestDigestion(ctx context.Context, cfg config, transport http.RoundTripper) (float64, bool) { + if cfg.maxDigestWait <= 0 { + return 0, false + } + pollClient := &http.Client{Timeout: 5 * time.Second, Transport: transport} + start := time.Now() + deadline := start.Add(cfg.maxDigestWait) + var prev *ingestStatsSnapshot + for time.Now().Before(deadline) { + if ctx.Err() != nil { + return time.Since(start).Seconds(), false + } + _, cur := fetchDeepHealth(ctx, cfg, pollClient) + if cur.Reachable { + if cur.DBSizeBytes == 0 && cur.WALSizeBytes == 0 { + return time.Since(start).Seconds(), false + } + if prev != nil && prev.DBSizeBytes == cur.DBSizeBytes && prev.WALSizeBytes == cur.WALSizeBytes { + return time.Since(start).Seconds(), false + } + snap := cur + prev = &snap + } else { + // A slow or failed poll is the engine (or the box) not answering — + // it breaks the stability streak rather than counting toward it. + prev = nil + } + select { + case <-time.After(5 * time.Second): + case <-ctx.Done(): + return time.Since(start).Seconds(), false + } + } + return time.Since(start).Seconds(), true +} + // probeReadEndpoint issues one HTTP request for the given endpoint and returns // wall-clock latency in ms plus any error. Hard-capped at threshold + 1s so a // hanging SUT can't deadlock the loop. diff --git a/benchmarks/scripts/run-matrix-entry.sh b/benchmarks/scripts/run-matrix-entry.sh index bf4013ec2..067e58a75 100755 --- a/benchmarks/scripts/run-matrix-entry.sh +++ b/benchmarks/scripts/run-matrix-entry.sh @@ -107,6 +107,21 @@ if [[ "${SCENARIO}" == "read-probe" ]]; then if [[ -n "${BENCH_FILL_LEVELS:-}" ]]; then extra_args+=( --fill-levels "${BENCH_FILL_LEVELS}" ) fi + # Diagnostic threshold override (e.g. 60000). The probe timeout is + # threshold + 1s, so raising this reveals how long a slow query actually + # takes instead of truncating it at the default 6s. Headline runs keep + # the 5000 default so results stay comparable across the series. + if [[ -n "${BENCH_READ_THRESHOLD_MS:-}" ]]; then + extra_args+=( --read-threshold-ms "${BENCH_READ_THRESHOLD_MS}" ) + fi +fi + +# Throughput Phase 2 ladder override (e.g. 1,5,10,15,20,25). The default +# 5-to-25 jump can skip straight from a passing step to one that kills the +# SUT, and post-fail bisection needs a live SUT — a finer ramp pins the +# cliff from the passing side instead. Loadgen ignores it outside throughput. +if [[ "${SCENARIO}" == "throughput" && -n "${BENCH_PHASE2_REQUEST_RATES:-}" ]]; then + extra_args+=( --phase2-request-rates "${BENCH_PHASE2_REQUEST_RATES}" ) fi # SQLite and DuckDB have no merge-idle equivalent — /health/deep returns diff --git a/website/content/blog/sqlite-vs-duckdb.mdx b/website/content/blog/sqlite-vs-duckdb.mdx new file mode 100644 index 000000000..6107a165c --- /dev/null +++ b/website/content/blog/sqlite-vs-duckdb.mdx @@ -0,0 +1,158 @@ +--- +title: "SQLite vs DuckDB on the same $16 box: every cliff moved 100x" +date: "2026-07-21" +category: "engineering" +author: "jovan" +description: "Same $16.49/month server, same Traceway binary, two embedded databases. DuckDB writes 4x to 15x faster than SQLite, serves dashboards at 100x the row count, and stores a billion metric points in 10.8 GB. Full numbers and methodology inside." +--- + +## TL;DR + +I spent six days working on and running a benchmark of observability data on DuckDB. I've done this with SQLite in [the last blog post](/blog/break-sqlite-traceway) and I really wanted to see how DuckDB compares on a cheap CCX13 Hetzner instance. The way I've done the measurements is by implementing DuckDB as a valid storage engine for Traceway and then running its benchmarking suite. The benchmarks show that DuckDB's columnar engine is able to query 100x more data points without any major backend changes. The write throughput is also 3x to 15x higher. The result is that you can now self-host the full OTel stack that can handle a large data volume on a pretty small server. Keep reading to find out how I've done the measurements! + +This is what came back: + +| | SQLite (post 2) | DuckDB (this post) | Change | +|---|---|---|---| +| Metrics writes | 61,712 pts/sec | 254,242 pts/sec | 4x | +| Spans writes | 30,508 spans/sec | 95,737 spans/sec | 3x | +| Logs writes | 4,877 rec/sec | 75,225 rec/sec | 15x | +| Metrics read cliff | 1M rows (3.85 s median) | 100M rows (3.0 s median) | 100x | +| Spans read cliff | 100k rows (2.27 s median) | 10M rows (902 ms median) | 100x | +| Logs read cliff | 100k rows (114 ms median) | 10M rows (85 ms median) | 100x | + +A read cliff, throughout this series, is the largest table size at which real dashboard pages still load: the median of three endpoint probes at or under 5 seconds, none timing out. It earns the name because of what sits one 10x step past it: queries don't slow down, they stop coming back. + +Each signal's read cliff sits exactly 100x further out on DuckDB than on SQLite, at equal or better latency, on identical hardware. I checked that symmetry against the raw JSON twice before I believed it. The box also ingested a billion metric points in under an hour into 10.8 GB of disk and stayed up, a scale the SQLite benchmark never got within 100x of. Logs, the signal post 2 said to keep off SQLite entirely, are DuckDB's biggest win. + +## What's actually being compared + +Post 2 ended promising a ClickHouse comparison, and that post is still coming. But every time I sat down to build it, the same question got in front of me: before reaching for a client-server OLAP database, with its own container, its own memory appetite, its own failure modes, how far does an embedded one go? Traceway ships a DuckDB telemetry backend as an opt-in build, same single binary, same deployment story as the SQLite build, different storage engine under the telemetry tables. If you self-host on one cheap box, these two builds are the actual decision in front of you, and I couldn't find anyone who had published numbers for it. So I ran post 2's entire methodology against the DuckDB build and put the results side by side. + +Here's the plan. Methodology first, including what changed in the harness since post 2 and one fix in the backend itself that these numbers depend on. Then writes, all three signals against their SQLite baselines. Then reads, same shape. Then the billion-row run, what queries cost past the cliffs, the fleet math for both builds, and which build I would actually run. + +## How I measured + +The setup is post 2's, so I'll keep it short: a system under test (SUT) running the Traceway binary and a separate load generator on a private link, both in Hetzner's Nuremberg datacenter, OTLP, the OpenTelemetry wire protocol, over gzipped protobuf, uniform-random data in bounded ranges. Traceway built from commit [`14b4aa6e`](https://github.com/tracewayapp/traceway/commit/14b4aa6e175946d40383d938db22cfea8c23c695), Ubuntu 24.04, retention off during the bench. + +Two scenarios per signal. The **throughput ramp**: batch-size ramp at fixed rate, then a request-rate ramp at the winning batch (this time with a finer rate ladder, 1 through 25 req/sec, because the interesting cliffs turned out to sit between post 2's coarser steps), then a small-batch high-rate ramp shaped like an SDK fleet. A step passes at under 5% errors and at least 70% of target rate achieved. The **read-probe**: fill the table to 1M, 10M, 100M, 1B, then 5B rows, and at each level load three real dashboard endpoints per signal, with a level passing when the median is at or under 5 s and nothing hits the 6 s timeout. The 5-second bar is generous on purpose and post 2's discussion of that still applies unchanged. + +Three things differ from post 2's harness, all disclosed: + +1. **The loadgen grew.** Post 2 generated load from a second CCX13, which SQLite's ceilings never stressed. On my first DuckDB spans run, that loadgen box died mid-ramp while the database sat at 0% errors, the traffic generator broke before the thing it was breaking. The loadgen is now a CCX23. The SUT, the box every number describes, is unchanged. +2. **The digestion gate.** DuckDB checkpoints its write-ahead log after ingest stops; probe during that and you measure a busy engine, not a query. The read-probe now polls the backend's deep-health endpoint until the database and WAL file sizes are stable, records the wait per level (5 seconds at every level in the final runs), then probes. SQLite reports no engine gauges and skips the wait, so its post 2 numbers were produced identically. +3. **Only accepted rows count.** The fill counts items confirmed by 2xx responses, not items attempted, which matters once the backend learns to refuse work. Fills overshoot their targets, at the smallest level by as much as 2.6x, so I quote actual row counts wherever the difference matters. + +Caveats. These are single-shot runs, one throughput run and one read ladder per signal. Post 2 promised medians of three reps starting with this post, and I'm walking that back one more time: the fix-and-rerun cycle below consumed the budget, and I'd rather publish single-shot numbers with that admission than sit on them. The key cells reproduced across the debugging runs (100M metrics reads landed between 2.7 s and 3.2 s across four runs on different days), but the protocol is single-shot. "Passing" still means three named endpoints on freshly written data on an otherwise idle box; read-under-ingest remains future work. + +One more disclosure, this one in the backend rather than the harness. My first DuckDB runs produced numbers I could not trust: the box kept dying mid-benchmark, and the hunt led to a real bug in my own ingest path, which had no admission control and let a sustained burst of fat batches run the process out of memory. I fixed it with an ingest gate that caps concurrent processing and answers overload with a 503 plus Retry-After (the commit linked above), and reran everything. All numbers in this post are from the fixed backend; the pre-fix results still visible in the repo's history predate it and understate DuckDB, spans by 23% and logs by almost half, because the crashes were cutting the ramps short. SQLite never surfaced the bug, its slower insert path errors early under pressure, which is post 2's 5 req/sec logs wall doing its job. + +## Writes: 4x, 3x, 15x + +| Signal | SQLite | DuckDB | Winning shape (DuckDB) | Lowest failing step | +|---|---|---|---|---| +| Metrics | 61,712/sec | **254,242/sec** | batch 16384 × 20 req/sec, p50 3.2 s | 22.5 req/sec, 12.2% errors | +| Spans | 30,508/sec | **95,737/sec** | batch 16384 × 7.5 req/sec, p50 1.2 s | 8.75 req/sec, 9.7% errors | +| Logs | 4,877/sec | **75,225/sec** | batch 16384 × 5 req/sec, p50 3.0 s | 5.625 req/sec, 11.4% errors | + +Going in, my quiet bar for this table was "double SQLite and I'll call it a win," and the one cell I braced for was logs. Post 2's starkest result was logs writing at 4,877/sec into a wall at 5 req/sec so sharp that 1.5x more requests took the error rate from 0% to 98%. That wall is the cell that moved most: the DuckDB build writes logs at fifteen times SQLite's rate, and the wall became a slope of polite refusals. The signal with the lowest SQLite ceiling and the highest real-world volume is the one the columnar engine helps most, which is either obvious in hindsight or backwards from everything post 2 trained me to expect, and I held the second view until this table existed. + +The "lowest failing step" column matters as much as the headline column, and lowest is the right word: the ladder bisects between the last passing and first failing rate, so those are the smallest rates that fail, not the first failures in wall-clock order. Every failure in the column is the backend refusing work rather than falling over: the run logs show 503s from the admission gate, the archived JSON shows zero insert failures and zero dropped rows behind them, and the container finished all three runs with zero restarts. That is the same graceful-cliff behavior SQLite showed in post 2, and DuckDB only exhibits it because of the fix I disclosed above; before it, this table could not be produced at all. + +The bottom of each ramp holds one more first for the series: the SDK-fleet shape, hundreds of small batches per second rather than a few fat ones, which post 2 could only measure on SQLite. DuckDB sustains 53,091 metric points/sec, 36,577 spans/sec, and 30,442 log records/sec at batch 100. My early attempts never produced these numbers, the pre-fix backend died before that phase of the ramp could run, so seeing them appear at all was the first sign the reruns were measuring something the crashes had been eating. + +## Reads: every cliff, 100x later + +Writes were the appetizer; reads are why anyone reaches for a columnar engine, and they're where I had the most to lose. Post 2's most-quoted line was about read cliffs, the last row count where the dashboard still loads, and if DuckDB only matched SQLite here, the whole build would be a curiosity. Before running it I told myself I'd be satisfied if each signal's cliff moved 10x. + +| Fill level | Metrics | Spans | Logs | +|---|---|---|---| +| 1M | 146 ms | 139 ms | 27 ms | +| 10M | 382 ms | **902 ms** | **85 ms** | +| 100M | **3.0 s, passes** | over 60 s, fails | fails unevenly: body search 3.5 s, trace-id 2 ms, severity filter over 60 s | +| 1B | fill succeeds, queries over 60 s | not reached | not reached | + +Each cell is the median of three real endpoint probes after fill and digestion; bold marks each signal's last passing level. Two footnotes on the table itself. The levels are fill targets and the fills run over: the 1M level actually holds 1.7M rows for spans and logs and 2.6M for metrics, and every level above lands within 16% of target, so the exact row counts are in the JSON. And the over-60-s durations come from a second ladder run with the probe timeout raised to 60 seconds, which gets its own section below; the standard probe gives up at 6 s. I got 100x per signal, not 10x: SQLite's last passing levels were 1M, 100k, and 100k, and all three moved by the same factor of one hundred. Same endpoints, same thresholds. + +Metrics reads scale gently: 146 ms at 1M, 382 ms at 10M, 3.0 s at 100M. A hundred times the rows costs twenty times the latency, the scan gets cheaper per row as the table grows. The level SQLite barely passed is a hundredth of the level DuckDB passes with the same margin. + +![Per-endpoint read latency vs metric_points table size on log-log axes. All three probes sit under 250 ms at 1M rows, under 700 ms at 10M, and between 2.4 and 5 s at 100M, still under the threshold](/blog/sqlite-vs-duckdb/chart-readprobe-metrics.webp) + +Spans pay for their percentiles, same as they did on SQLite, just later. This is the page doing the paying, shown on my local instance with the loadgen's spans: + +![The Traceway endpoints page over loadgen spans: thirteen synthetic routes at around 219k calls each, P50 around 505 ms, slow bucket 950 ms, the shapes the loadgen emits, not Traceway's overhead](/blog/sqlite-vs-duckdb/img-endpoints-page.webp) + +Every row in that table is a P50/P95/P99 aggregation over the spans behind it, and the stacked latency chart above it is a second aggregation. Those two queries cost 902 ms at 10M rows and blow past a full minute at 100M. Post 2 watched the same two pages die between 100k and 1M. + +![Per-endpoint read latency vs spans table size on log-log axes. The two percentile-aggregation probes track from under 200 ms at 1M to about 900 ms at 10M, then exceed the timeout at 100M](/blog/sqlite-vs-duckdb/chart-readprobe-spans.webp) + +Logs are the numbers I trusted least and checked hardest, an early bad run had me convinced for a full day that DuckDB couldn't read logs at all, and the truth turned out to be post 2's most interesting pattern repeated at ten times the rows. Here's the page in question, on my local instance with the loadgen's log records: + +![The Traceway logs page over loadgen data: INFO, WARN, and ERROR records with realistic bodies like "slow query detected" and "payment authorized via stripe", a service column, and truncated trace IDs](/blog/sqlite-vs-duckdb/img-logs-page.webp) + +At their passing levels logs are the fastest dashboard of the three (85 ms median at 10M), and their failure at 100M is uneven in the same way SQLite's was at 1M: the trace-ID lookup still answers in 2 ms, the body search in 3.5 s, and only the severity filter, which matches and ranks a large slice of 100M rows, dies. The pages an on-call actually opens mid-incident, find this trace, search this error, remain usable at 100M rows; the full-table scan does not. Retention policy should still follow that split. The split just moved 100x. + +![Per-endpoint read latency vs log_records table size on log-log axes. The trace-id lookup stays at 2 ms across every level, the body search holds under 100 ms to 10M and reaches 3.5 s at 100M, and the severity filter crosses the threshold at 100M](/blog/sqlite-vs-duckdb/chart-readprobe-logs.webp) + +## A billion rows on an 80 GB disk + +I put the 1B level on the ladder expecting to write a paragraph about how it died, because every earlier attempt at it had ended the same way: container gone, level unreadable. This time the final fill step alone ran for 52 minutes, adding its last 900M points at a sustained 287k points/sec with the gate shedding the excess, and brought the table to 1,001,472,000 rows in **10.8 GB on disk**, about 10.8 bytes per point after columnar compression, under an hour of total ingest across the ladder. The box stayed up. Health checks answered the whole way through, and post-fill digestion took 5 seconds. Nothing in posts 1 or 2 gets within 100x of this level; on the fixed backend a billion rows is just a big table. + +A big table you cannot look at: all three dashboard queries ran past 60 seconds at 1B, so the level fails, and 5B was never attempted since the ladder stops at the first failure. I left it that way on purpose. A 5B fill would prove the disk holds 54 GB of points, and I already know nothing could read them. The practical summary of the ladder's top: this box can store a billion metric points, and it can show you a hundred million of them. + +## How slow is slow past the cliff + +Post 2 could only say "it timed out" about anything past a cliff. This time I reran the entire ladder with a 60-second probe threshold to put real durations on the failing cells, and there were no durations to put: every failing query was still running when the new cap cut it off. Metrics at 1B, still running at 61 s. Spans aggregations at 100M, still running at 61 s. The logs severity filter at 100M, still running at 61 s while the body search finished in 3.2 s beside it. + +So the cliffs are not slopes on either database. Queries go from a second or three to more than a minute across a single 10x step in rows, the signature of an aggregation outgrowing the 4 GB memory budget and spilling. Post 2 found the same absence on SQLite at one hundredth the scale, and it is why I keep publishing cliffs instead of curves: there is no slow-but-usable band above a cliff to plan around. + +The 60-second run also caught a smaller flaw for the fix list: a cancelled dashboard query does not promptly release its read-pool connection, so after the two spans aggregations timed out, a 3 ms exceptions query queued behind them for 52 seconds. It affected no passing number, and it goes on the same list the admission gate came from. + +## What fits comfortably, on each build + +Cliffs are ceilings; what matters day to day is how far under them a real fleet sits. The small-fleet shape from post 2, ten backends emitting 50 spans/sec, 200 log records/sec, and 10 metric points/sec each, held against both builds: + +| | SQLite envelope used | DuckDB envelope used | +|---|---|---| +| Spans (500/sec) | 1.7% | 0.5% | +| Logs (2,000/sec) | **40%** | 2.7% | +| Metrics (100/sec) | 0.2% | 0.04% | + +Writes were already a non-issue on SQLite for everything except logs, and on DuckDB they stop being a conversation entirely. Retention is still the real knob, with new units. At this fleet's rates, logs reach their last passing read level (10M rows) in about 85 minutes and the failing level in about 14 hours; spans reach 10M in 5.5 hours; metrics reach 100M in 11 days. On SQLite, post 2 measured the logs window at 50 seconds. An incident-sized working set, hours of spans and logs, days of metrics, fits on the right side of every DuckDB cliff with an ordinary retention job, which is the thing the SQLite build could not offer. + +## What I deliberately didn't measure + +- **Read under concurrent write.** Fill, digest, settle, probe. Stricter isolation than post 2, and still not what a dashboard experiences at 3 PM. Top of the future-work list. +- **Mixed-signal load.** Each signal had the box to itself; a real deployment writes all three at once and these ceilings do not simply add. +- **Result correctness.** I timed responses, I did not diff their contents. +- **Variance.** Single-shot, as admitted in the methodology, with the median-of-three protocol still owed. +- **Tuning.** Stock config, meaning what the benchmark compose file ships by default: 4 GB DuckDB memory cap, 256 MB checkpoint threshold, no schema or query changes. The 1B read failure smells like it wants a memory-budget experiment, and that is a deliberate cliffhanger. +- **ClickHouse.** The comparison post 2 promised is still owed, and it gets its own post on these same ladders rather than a section squeezed in here. +- **Durability over weeks.** An hour-long billion-row fill says nothing about month three on the same disk. + +## What surprised me + +I expected the reads to win, that's what columnar storage is for, and I set my bar at 10x per signal. All three delivered 100x. But the thing that will stay with me from this week is that the database was never the hard part: every wrong-looking number in six days of benchmarking traced back to my own ingest path, not the engine. DuckDB, whenever my code got out of its way, was boring in the best way a database can be boring. + +The other surprise was logs, again. Post 2's verdict was "keep logs off SQLite," and logs turned out to be the strongest single argument for the DuckDB build: 15x on writes, 100x on the read cliff, with the incident-workflow pages still answering at 100M rows. + +## The verdict + +Post 1 claimed a $16 box could run your observability stack. Post 2 tested the claim and returned it with an exception: not logs, and mind the read cliffs. This post retires the exception. On the same box, the DuckDB build writes every signal faster than a small fleet emits, serves dashboards at row counts the SQLite build cannot approach, and turns logs from the signal post 2 told you to keep off the box into the best result in the dataset. A billion metric points cost 10.8 GB of disk. I came into the week hoping to double post 2's numbers; the smallest improvement in the table is 3x. + +So if you self-host Traceway on a single machine, run the DuckDB build ([`docker-compose.duckdb.yml`](https://github.com/tracewayapp/traceway/blob/main/docker-compose.duckdb.yml) in the repo brings it up). One config note before you do: that compose file ships a conservative 2 GB DuckDB memory cap and leaves the checkpoint threshold at DuckDB's 16 MB default, while the benchmark ran on 4 GB and 256 MB, so set `DUCKDB_MEMORY_LIMIT` and `DUCKDB_CHECKPOINT_THRESHOLD` to match if you want these numbers. I would only reach for the SQLite build in two situations, and both are real. If you need a binary that compiles anywhere Go does, SQLite wins: the DuckDB build needs CGO, Go's C bridge, and glibc, so its container image is Debian rather than Alpine. And if your volume lives comfortably under post 2's numbers, SQLite's storage engine doing all its work inline, no deferred checkpoints, no digestion window to wait out, remains the simplest thing that works. The moment logs matter, or retention past an hour matters, the comparison stops being close. + +One asterisk belongs on the whole table: these numbers exist because the benchmark first found a crash bug in my ingest path, and I fixed it before rerunning everything. If you run the DuckDB build, run a version with the admission gate. The engine was never the problem. The code in front of it was, and finding that out is the most useful thing this comparison produced. + +## Raw data + workflow + +Everything in this post, runnable from the repo: + +- **Raw JSON** lives in [`benchmarks/blog/post-3-data/`](https://github.com/tracewayapp/traceway/tree/main/benchmarks/blog/post-3-data): throughput, read-probe, and 60-second diagnostic JSONs, one per signal. +- **The workflow**: [`benchmark-hardware.yml`](https://github.com/tracewayapp/traceway/actions/workflows/benchmark-hardware.yml). Throughput: [29828430297](https://github.com/tracewayapp/traceway/actions/runs/29828430297). Read-probe: [29838394873](https://github.com/tracewayapp/traceway/actions/runs/29838394873). 60-second diagnostic: [29848976962](https://github.com/tracewayapp/traceway/actions/runs/29848976962). The pre-fix runs the methodology disclosure mentions: [29734966806](https://github.com/tracewayapp/traceway/actions/runs/29734966806) and [29815312404](https://github.com/tracewayapp/traceway/actions/runs/29815312404). +- **The fix**: commit [`14b4aa6e`](https://github.com/tracewayapp/traceway/commit/14b4aa6e175946d40383d938db22cfea8c23c695), the ingest admission gate. +- **Try Traceway**: [self-host in five minutes](/docs/install). + +Questions, pushback, or "your number is wrong because X": `jstojiljkovic941@gmail.com`, or find me on [GitHub](https://github.com/jstojiljkovic). + +**Next post:** the one post 2 promised. ClickHouse on the same box, same loadgen, same ladders, to find out what the full client-server stack buys you over the embedded engines and what it costs to get it. diff --git a/website/public/blog/sqlite-vs-duckdb/chart-readprobe-logs.webp b/website/public/blog/sqlite-vs-duckdb/chart-readprobe-logs.webp new file mode 100644 index 000000000..7b73c28c9 Binary files /dev/null and b/website/public/blog/sqlite-vs-duckdb/chart-readprobe-logs.webp differ diff --git a/website/public/blog/sqlite-vs-duckdb/chart-readprobe-metrics.webp b/website/public/blog/sqlite-vs-duckdb/chart-readprobe-metrics.webp new file mode 100644 index 000000000..756bd7ae2 Binary files /dev/null and b/website/public/blog/sqlite-vs-duckdb/chart-readprobe-metrics.webp differ diff --git a/website/public/blog/sqlite-vs-duckdb/chart-readprobe-spans.webp b/website/public/blog/sqlite-vs-duckdb/chart-readprobe-spans.webp new file mode 100644 index 000000000..6622b13bb Binary files /dev/null and b/website/public/blog/sqlite-vs-duckdb/chart-readprobe-spans.webp differ diff --git a/website/public/blog/sqlite-vs-duckdb/img-endpoints-page.webp b/website/public/blog/sqlite-vs-duckdb/img-endpoints-page.webp new file mode 100644 index 000000000..806010e46 Binary files /dev/null and b/website/public/blog/sqlite-vs-duckdb/img-endpoints-page.webp differ diff --git a/website/public/blog/sqlite-vs-duckdb/img-logs-page.webp b/website/public/blog/sqlite-vs-duckdb/img-logs-page.webp new file mode 100644 index 000000000..f20131ff6 Binary files /dev/null and b/website/public/blog/sqlite-vs-duckdb/img-logs-page.webp differ