diff --git a/CLAUDE.md b/CLAUDE.md index 324643c4b..30516523d 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -255,12 +255,20 @@ POSTGRES_SSLMODE=disable # DuckDB telemetry backend (only with -tags telemetry_duckdb build; see "DuckDB Telemetry Backend" below) DUCKDB_MEMORY_LIMIT= # e.g. 4GB. Unset = DuckDB auto-tunes (~80% RAM). Set explicitly in memory-capped containers to avoid OOM. 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. +DUCKDB_CHECKPOINT_THRESHOLD= # WAL checkpoint threshold. Unset = 256MB (backend default; DuckDB's own 16MB default stalls sustained ingest). Lower it if restart replay time matters more than ingest throughput. +DUCKDB_WRITE_QUEUE_ROWS=131072 # background write batcher: per-table queue capacity in rows. A full queue answers 503 + Retry-After (load shedding before the ack). +DUCKDB_WRITE_FLUSH_ROWS=32768 # flush the per-table appender after this many rows +DUCKDB_WRITE_FLUSH_INTERVAL_MS=100 # ...or after this age, whichever first. Bounds read-lag and the acked-data loss window on crash. +DUCKDB_WRITE_WRITERS= # writer goroutines per hot table. Unset = 2 x CPU cores, capped at 8 (VictoriaMetrics-style drain concurrency). +DUCKDB_WRITE_QUEUE_WAIT_MS=2000 # how long enqueue waits for queue space before the 503 (VictoriaMetrics-style insert queueing). Bursts the writers sustain on average are absorbed instead of rejected. # 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 +# Profiling (opt-in) +PPROF_PORT= # e.g. 6060. Serves net/http/pprof on 127.0.0.1: (localhost only; unreachable through the public router). Unset = disabled. + # Notifications NOTIFICATION_POLL_SECONDS=60 # polled rule evaluation interval; minimum 5, invalid values fall back to 60 @@ -799,8 +807,8 @@ for _, item := range items { Built with `-tags telemetry_duckdb` (`CGO_ENABLED=1` required), this is an alternative telemetry store for the same `DB_TYPE=sqlite` deployment: the **main DB stays SQLite** (`db.DB`, relational/config), while the **telemetry DB becomes DuckDB** (`db.TelemetryDB`, columnar). It exists because DuckDB's columnar engine is dramatically faster on the analytics/aggregation reads the dashboard issues — at 10M rows it clears read-probe thresholds that SQLite times out on. Backends are selected on two build-tag axes: `telemetry_ch` / `telemetry_duckdb` / *(none = SQLite telemetry)* for the telemetry store and `transactional_pg` / *(none = SQLite main)* for the relational store. Only three combinations are supported — *(no tags)* dual SQLite, `telemetry_duckdb`, and `transactional_pg telemetry_ch` — enforced by compile-time guard files in `backend/app/db/` (stale `pgch`/`duckdb`/`oltp_*` tags also fail with a rename message). Repositories are organized on the same two axes: telemetry repositories live in per-backend packages `backend/app/repositories/telemetry/{clickhouse,sqlite,duckdb}/` and transactional (relational) repositories in `backend/app/repositories/transactional/{pg,sqlite}/`, each re-exported as singletons through tag-guarded facade files at the axis package root (`telemetry/telemetry_ch.go` etc., `transactional/transactional_pg.go` etc.). Consumers import the facade packages — `telemetry.SpanRepository`, `transactional.UserRepository` — never a backend package directly. Helpers shared by all telemetry backends are in `telemetry/shared/`, the SQLite scan/value types shared by the sqlite+duckdb backends are in `telemetry/sqlitetypes/`, and helpers/types shared by the transactional backends (auth-token hashing/time formats, facade-crossing structs) are in `transactional/shared/`. The `transactional/pg` and `transactional/sqlite` implementations are intentionally kept dialect-neutral (lit `:name` queries rendered per `db.Driver`), enforced byte-for-byte by `transactional/parity_test.go`. Running Postgres requires the `transactional_pg` build: the default build's migration runner applies SQLite-dialect migrations unconditionally, so `DB_TYPE=postgres` without the tag is not a supported combination. - **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). +- **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 tune the WAL checkpoint threshold (backend default 256MB; DuckDB's own default of 16MB stalls sustained Appender ingest with 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). The five hot tables (`spans`, `metric_points`, `log_records`, `endpoints`, `tasks`) additionally go through a **background write batcher** (`telemetry/duckdb/writer.go`, started via `telemetry.StartWriters` in `cmd/run.go`): the request goroutine converts models to rows and enqueues onto a bounded per-table queue, one writer goroutine per table owns a persistent connection + Appender and flushes at `DUCKDB_WRITE_FLUSH_ROWS`/`DUCKDB_WRITE_FLUSH_INTERVAL_MS`. A 200 therefore means "accepted into the queue" (OTel-Collector-style ack-before-durable, loss window ≤ one flush); a full queue returns `db.ErrIngestQueueFull`, which controllers map to 503 + Retry-After (`middleware.AbortIngestInsertError`; the Retry-After hint tracks the configured queue wait) — overload is shed before the ack, acked rows are never silently dropped. `telemetry.FlushWriters` is a barrier used by the notification event evaluator (it reads back just-ingested rows) and tests; when writers aren't started (tests), `InsertAsync` falls back to the synchronous per-request appender. The other tables stay synchronous: `exception_stack_traces` (evaluator read-back), `sessions`/`profiling_stacks` (ordering-sensitive upserts), and the low-volume rest. 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). - **`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). diff --git a/backend/app/config/config.go b/backend/app/config/config.go index b9df860d2..06504675c 100644 --- a/backend/app/config/config.go +++ b/backend/app/config/config.go @@ -14,9 +14,14 @@ type Cfg struct { PostgresSSLMode string SQLitePath string - DuckDBMemoryLimit string - DuckDBThreads string - DuckDBCheckpointThreshold string + DuckDBMemoryLimit string + DuckDBThreads string + DuckDBCheckpointThreshold string + DuckDBWriteQueueRows string + DuckDBWriteFlushRows string + DuckDBWriteFlushIntervalMS string + DuckDBWriteWriters string + DuckDBWriteQueueWaitMS string ClickhouseServer string ClickhouseDatabase string @@ -61,6 +66,7 @@ type Cfg struct { MonitoringTracewayURL string APIOnly string Ports string + PprofPort string TurnstileSecretKey string GoogleClientID string @@ -102,9 +108,14 @@ func LoadFromEnv() *Cfg { PostgresSSLMode: os.Getenv("POSTGRES_SSLMODE"), SQLitePath: os.Getenv("SQLITE_PATH"), - DuckDBMemoryLimit: os.Getenv("DUCKDB_MEMORY_LIMIT"), - DuckDBThreads: os.Getenv("DUCKDB_THREADS"), - DuckDBCheckpointThreshold: os.Getenv("DUCKDB_CHECKPOINT_THRESHOLD"), + DuckDBMemoryLimit: os.Getenv("DUCKDB_MEMORY_LIMIT"), + DuckDBThreads: os.Getenv("DUCKDB_THREADS"), + DuckDBCheckpointThreshold: os.Getenv("DUCKDB_CHECKPOINT_THRESHOLD"), + DuckDBWriteQueueRows: os.Getenv("DUCKDB_WRITE_QUEUE_ROWS"), + DuckDBWriteFlushRows: os.Getenv("DUCKDB_WRITE_FLUSH_ROWS"), + DuckDBWriteFlushIntervalMS: os.Getenv("DUCKDB_WRITE_FLUSH_INTERVAL_MS"), + DuckDBWriteWriters: os.Getenv("DUCKDB_WRITE_WRITERS"), + DuckDBWriteQueueWaitMS: os.Getenv("DUCKDB_WRITE_QUEUE_WAIT_MS"), ClickhouseServer: os.Getenv("CLICKHOUSE_SERVER"), ClickhouseDatabase: os.Getenv("CLICKHOUSE_DATABASE"), @@ -149,6 +160,7 @@ func LoadFromEnv() *Cfg { MonitoringTracewayURL: os.Getenv("MONITORING_TRACEWAY_URL"), APIOnly: os.Getenv("API_ONLY"), Ports: os.Getenv("PORTS"), + PprofPort: os.Getenv("PPROF_PORT"), TurnstileSecretKey: os.Getenv("TURNSTILE_SECRET_KEY"), GoogleClientID: os.Getenv("GOOGLE_CLIENT_ID"), diff --git a/backend/app/controllers/clientcontrollers/client.controller.go b/backend/app/controllers/clientcontrollers/client.controller.go index 3f42b4fd2..929cf7c8c 100644 --- a/backend/app/controllers/clientcontrollers/client.controller.go +++ b/backend/app/controllers/clientcontrollers/client.controller.go @@ -305,7 +305,7 @@ func (e clientController) Report(c *gin.Context) { err := telemetry.EndpointRepository.InsertAsync(c, endpointsToInsert) insertSpan.End() if err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting endpointsToInsert: %w", err)) + middleware.AbortIngestInsertError(c, err, "endpointsToInsert") return } } @@ -315,7 +315,7 @@ func (e clientController) Report(c *gin.Context) { err := telemetry.TaskRepository.InsertAsync(c, tasksToInsert) insertSpan.End() if err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting tasksToInsert: %w", err)) + middleware.AbortIngestInsertError(c, err, "tasksToInsert") return } } @@ -344,7 +344,7 @@ func (e clientController) Report(c *gin.Context) { err := telemetry.MetricPointRepository.InsertAsync(c, metricPointsToInsert) insertSpan.End() if err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting metricPointsToInsert: %w", err)) + middleware.AbortIngestInsertError(c, err, "metricPointsToInsert") return } @@ -357,7 +357,7 @@ func (e clientController) Report(c *gin.Context) { spanInsertSpan.End() if err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting spansToInsert: %w", err)) + middleware.AbortIngestInsertError(c, err, "spansToInsert") return } diff --git a/backend/app/controllers/health_deep.go b/backend/app/controllers/health_deep.go index 999cc5ade..220be2ba0 100644 --- a/backend/app/controllers/health_deep.go +++ b/backend/app/controllers/health_deep.go @@ -36,6 +36,7 @@ type HealthDeepResponse struct { DroppedRowsTotal uint64 `json:"droppedRowsTotal"` InsertFailures uint64 `json:"insertFailures"` IngestRejected uint64 `json:"ingestRejected"` + WriteQueueDepth map[string]int `json:"writeQueueDepth,omitempty"` Engine *db.TelemetryEngineStats `json:"engine,omitempty"` } @@ -51,6 +52,9 @@ func (h healthDeepController) Get(c *gin.Context) { resp.DroppedRowsTotal = droppedTotal resp.InsertFailures = insertFailures resp.IngestRejected = db.GetIngestRejects() + if depths, ok := db.GetTelemetryWriteQueueDepths(); ok { + resp.WriteQueueDepth = depths + } if engine, ok := db.GetTelemetryEngineStats(c.Request.Context()); ok { resp.Engine = &engine } diff --git a/backend/app/controllers/otelcontrollers/codec.go b/backend/app/controllers/otelcontrollers/codec.go index 5eb3d0296..20f10c8a6 100644 --- a/backend/app/controllers/otelcontrollers/codec.go +++ b/backend/app/controllers/otelcontrollers/codec.go @@ -1,11 +1,13 @@ package otelcontrollers import ( + "bytes" "compress/gzip" "fmt" "io" "net/http" "strings" + "sync" "github.com/gin-gonic/gin" collogspb "go.opentelemetry.io/proto/otlp/collector/logs/v1" @@ -18,17 +20,48 @@ import ( const maxBodySize = 10 * 1024 * 1024 // 10MB -func readBody(c *gin.Context) ([]byte, error) { +// The decode path runs for every OTLP request; pooling the gzip reader and +// the decompressed-body buffer removes a reader setup and the io.ReadAll +// realloc ladder per request. Pooled memory never escapes this file: the +// body bytes are only valid until release() and proto/protojson unmarshal +// copies what it keeps. +var ( + gzipReaderPool sync.Pool + bodyBufPool = sync.Pool{New: func() any { return new(bytes.Buffer) }} +) + +func readBody(c *gin.Context) (body []byte, release func(), err error) { var reader io.Reader = c.Request.Body if strings.EqualFold(c.GetHeader("Content-Encoding"), "gzip") { - gr, err := gzip.NewReader(c.Request.Body) + var gr *gzip.Reader + if pooled, ok := gzipReaderPool.Get().(*gzip.Reader); ok { + gr = pooled + err = gr.Reset(c.Request.Body) + } else { + gr, err = gzip.NewReader(c.Request.Body) + } if err != nil { - return nil, fmt.Errorf("failed to create gzip reader: %w", err) + if gr != nil { + gzipReaderPool.Put(gr) + } + return nil, nil, fmt.Errorf("failed to create gzip reader: %w", err) } - defer gr.Close() + // The body is fully consumed below, so the reader can go back to + // the pool before returning. + defer func() { + gr.Close() + gzipReaderPool.Put(gr) + }() reader = gr } - return io.ReadAll(io.LimitReader(reader, maxBodySize)) + + buf := bodyBufPool.Get().(*bytes.Buffer) + buf.Reset() + if _, err := buf.ReadFrom(io.LimitReader(reader, maxBodySize)); err != nil { + bodyBufPool.Put(buf) + return nil, nil, err + } + return buf.Bytes(), func() { bodyBufPool.Put(buf) }, nil } func isProtobuf(c *gin.Context) bool { @@ -37,10 +70,11 @@ func isProtobuf(c *gin.Context) bool { } func decodeTraceRequest(c *gin.Context) (*coltracepb.ExportTraceServiceRequest, int, error) { - body, err := readBody(c) + body, release, err := readBody(c) if err != nil { return nil, 0, err } + defer release() req := &coltracepb.ExportTraceServiceRequest{} if isProtobuf(c) { if err := proto.Unmarshal(body, req); err != nil { @@ -55,10 +89,11 @@ func decodeTraceRequest(c *gin.Context) (*coltracepb.ExportTraceServiceRequest, } func decodeMetricsRequest(c *gin.Context) (*colmetricspb.ExportMetricsServiceRequest, int, error) { - body, err := readBody(c) + body, release, err := readBody(c) if err != nil { return nil, 0, err } + defer release() req := &colmetricspb.ExportMetricsServiceRequest{} if isProtobuf(c) { if err := proto.Unmarshal(body, req); err != nil { @@ -95,12 +130,15 @@ func writeMetricsResponse(c *gin.Context) { } func decodeProfilesPayload(c *gin.Context) ([]byte, int, error) { - body, err := readBody(c) + body, release, err := readBody(c) if err != nil { return nil, 0, err } + defer release() if isProtobuf(c) { - return body, len(body), nil + // The payload escapes to the profiling pipeline, so it must own its + // bytes — the pooled buffer is reused after release. + return bytes.Clone(body), len(body), nil } req := &colprofilespb.ExportProfilesServiceRequest{} if err := protojson.Unmarshal(body, req); err != nil { @@ -125,10 +163,11 @@ func writeProfilesResponse(c *gin.Context) { } func decodeLogsRequest(c *gin.Context) (*collogspb.ExportLogsServiceRequest, int, error) { - body, err := readBody(c) + body, release, err := readBody(c) if err != nil { return nil, 0, err } + defer release() req := &collogspb.ExportLogsServiceRequest{} if isProtobuf(c) { if err := proto.Unmarshal(body, req); err != nil { diff --git a/backend/app/controllers/otelcontrollers/otel.controller.go b/backend/app/controllers/otelcontrollers/otel.controller.go index 7d2b098cb..c3ddb8743 100644 --- a/backend/app/controllers/otelcontrollers/otel.controller.go +++ b/backend/app/controllers/otelcontrollers/otel.controller.go @@ -112,14 +112,14 @@ func (o otelController) ExportTraces(c *gin.Context) { if len(endpoints) > 0 { if err := telemetry.EndpointRepository.InsertAsync(c, endpoints); err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting OTEL endpoints: %w", err)) + middleware.AbortIngestInsertError(c, err, "OTEL endpoints") return } } if len(tasks) > 0 { if err := telemetry.TaskRepository.InsertAsync(c, tasks); err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting OTEL tasks: %w", err)) + middleware.AbortIngestInsertError(c, err, "OTEL tasks") return } } @@ -130,7 +130,7 @@ func (o otelController) ExportTraces(c *gin.Context) { } if err := telemetry.SpanRepository.InsertAsync(c, spans); err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting OTEL spans: %w", err)) + middleware.AbortIngestInsertError(c, err, "OTEL spans") return } @@ -237,7 +237,7 @@ func (o otelController) ExportMetrics(c *gin.Context) { if len(result.Points) > 0 { insertStart := time.Now() if err := telemetry.MetricPointRepository.InsertAsync(c, result.Points); err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting OTEL metric points: %w", err)) + middleware.AbortIngestInsertError(c, err, "OTEL metric points") return } insertMs = msSince(insertStart) @@ -308,7 +308,7 @@ func (o otelController) ExportLogs(c *gin.Context) { if len(records) > 0 { insertStart := time.Now() if err := telemetry.LogRecordRepository.InsertAsync(c, records); err != nil { - c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting OTEL log records: %w", err)) + middleware.AbortIngestInsertError(c, err, "OTEL log records") return } insertMs = msSince(insertStart) diff --git a/backend/app/db/db_telemetry_duckdb.go b/backend/app/db/db_telemetry_duckdb.go index 5205ab63c..4ae30de27 100644 --- a/backend/app/db/db_telemetry_duckdb.go +++ b/backend/app/db/db_telemetry_duckdb.go @@ -54,9 +54,14 @@ func openDuckDB(path string) error { if v := strings.TrimSpace(config.Config.DuckDBThreads); v != "" { q.Set("threads", v) } - if v := strings.TrimSpace(config.Config.DuckDBCheckpointThreshold); v != "" { - q.Set("checkpoint_threshold", v) + // DuckDB's own default (16MB) stalls sustained Appender ingest with + // frequent WAL checkpoints; the benchmark campaign ran 256MB, so that is + // the shipped default. Costs a larger WAL and longer restart replay. + checkpointThreshold := strings.TrimSpace(config.Config.DuckDBCheckpointThreshold) + if checkpointThreshold == "" { + checkpointThreshold = "256MB" } + q.Set("checkpoint_threshold", checkpointThreshold) dsn := path + "?" + q.Encode() connector, err := duckdb.NewConnector(dsn, nil) diff --git a/backend/app/db/telemetry_stats.go b/backend/app/db/telemetry_stats.go index b980d6ddf..678e82535 100644 --- a/backend/app/db/telemetry_stats.go +++ b/backend/app/db/telemetry_stats.go @@ -2,9 +2,36 @@ package db import ( "context" + "errors" "sync" + "sync/atomic" + "time" ) +// ErrIngestQueueFull is returned by telemetry insert methods when the +// background write queue for a table is at capacity. Controllers map it to +// 503 + Retry-After so the client retries — the data was never acked. +var ErrIngestQueueFull = errors.New("telemetry ingest write queue full") + +// Retry-After hint for the queue-full 503; the DuckDB writers set it from +// their configured queue wait. Zero means unset, the getter falls back to 2s. +var ingestQueueRetryAfterSeconds atomic.Int64 + +func SetIngestQueueRetryAfter(wait time.Duration) { + secs := int64((wait + time.Second - 1) / time.Second) + if secs < 1 { + secs = 1 + } + ingestQueueRetryAfterSeconds.Store(secs) +} + +func IngestQueueRetryAfterSeconds() int { + if s := ingestQueueRetryAfterSeconds.Load(); s > 0 { + return int(s) + } + return 2 +} + type TelemetryEngineStats struct { DBSizeBytes int64 `json:"dbSizeBytes"` WALSizeBytes int64 `json:"walSizeBytes"` @@ -60,6 +87,33 @@ func RecordTelemetryRowDropped(table string) { telemetryIngestMu.Unlock() } +// RecordTelemetryRowsDropped counts a bulk loss, e.g. a failed background +// flush discarding rows that were already acked to the client. +func RecordTelemetryRowsDropped(table string, n uint64) { + telemetryIngestMu.Lock() + telemetryDroppedRows[table] += n + telemetryIngestMu.Unlock() +} + +// Locked because tests start/stop writers at runtime; production sets it once. +var telemetryWriteQueueDepthFn func() map[string]int + +func SetTelemetryWriteQueueDepthFn(fn func() map[string]int) { + telemetryIngestMu.Lock() + telemetryWriteQueueDepthFn = fn + telemetryIngestMu.Unlock() +} + +func GetTelemetryWriteQueueDepths() (map[string]int, bool) { + telemetryIngestMu.Lock() + fn := telemetryWriteQueueDepthFn + telemetryIngestMu.Unlock() + if fn == nil { + return nil, false + } + return fn(), true +} + func RecordTelemetryInsertFailure() { telemetryIngestMu.Lock() telemetryInsertFailures++ diff --git a/backend/app/middleware/ingest_admission.go b/backend/app/middleware/ingest_admission.go index a95c521d7..9c4891326 100644 --- a/backend/app/middleware/ingest_admission.go +++ b/backend/app/middleware/ingest_admission.go @@ -1,14 +1,12 @@ package middleware import ( - "net/http" "os" "runtime" "strconv" "time" "github.com/gin-gonic/gin" - "github.com/tracewayapp/traceway/backend/app/db" ) // The telemetry ingest path decompresses and decodes every request body it @@ -31,9 +29,7 @@ func newIngestAdmission(capacity int, wait time.Duration) gin.HandlerFunc { 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"}) + AbortIngestSaturated(c, 2) return case <-c.Request.Context().Done(): c.Abort() diff --git a/backend/app/middleware/ingest_load_shed.go b/backend/app/middleware/ingest_load_shed.go new file mode 100644 index 000000000..384767dd3 --- /dev/null +++ b/backend/app/middleware/ingest_load_shed.go @@ -0,0 +1,33 @@ +package middleware + +import ( + "errors" + "net/http" + "strconv" + + "github.com/gin-gonic/gin" + "github.com/tracewayapp/traceway/backend/app/db" + traceway "go.tracewayapp.com" +) + +// AbortIngestSaturated is the shared load-shedding response — 503 + +// Retry-After, counted in the ingest-rejected metric — so the admission gate +// and the full-write-queue path answer with one shape. +func AbortIngestSaturated(c *gin.Context, retryAfterSeconds int) { + db.RecordIngestRejected() + c.Header("Retry-After", strconv.Itoa(retryAfterSeconds)) + c.AbortWithStatusJSON(http.StatusServiceUnavailable, gin.H{"error": "ingest saturated, retry later"}) +} + +// AbortIngestInsertError maps a full telemetry write queue to the same +// 503 + Retry-After the admission gate sends: it is load shedding, not a +// server fault, and SDKs and OTLP clients retry 503. A mixed request that +// already enqueued other tables is retried whole — duplicates are acceptable +// under at-least-once ingest semantics. Everything else stays a 500. +func AbortIngestInsertError(c *gin.Context, err error, what string) { + if errors.Is(err, db.ErrIngestQueueFull) { + AbortIngestSaturated(c, db.IngestQueueRetryAfterSeconds()) + return + } + c.AbortWithError(500, traceway.NewStackTraceErrorf("error inserting %s: %w", what, err)) +} diff --git a/backend/app/middleware/use_gzip_decompress.middleware.go b/backend/app/middleware/use_gzip_decompress.middleware.go index 47c73bded..34e528c76 100644 --- a/backend/app/middleware/use_gzip_decompress.middleware.go +++ b/backend/app/middleware/use_gzip_decompress.middleware.go @@ -3,10 +3,13 @@ package middleware import ( "compress/gzip" "net/http" + "sync" "github.com/gin-gonic/gin" ) +var gzipRequestReaderPool sync.Pool + func UseGzip(c *gin.Context) { // Decompress when Content-Encoding announces gzip; otherwise pass the // body through untouched. The pagehide / keepalive code path in the SDK @@ -18,11 +21,25 @@ func UseGzip(c *gin.Context) { return } - gzReader, err := gzip.NewReader(c.Request.Body) + var gzReader *gzip.Reader + var err error + if pooled, ok := gzipRequestReaderPool.Get().(*gzip.Reader); ok { + gzReader = pooled + err = gzReader.Reset(c.Request.Body) + } else { + gzReader, err = gzip.NewReader(c.Request.Body) + } if err != nil { + if gzReader != nil { + gzipRequestReaderPool.Put(gzReader) + } c.AbortWithStatusJSON(http.StatusBadRequest, gin.H{"error": "Invalid gzip"}) return } c.Request.Body = gzReader c.Next() + // The handler chain is synchronous and done with the body here; nothing + // retains it past the request, so the reader can be reused. + gzReader.Close() + gzipRequestReaderPool.Put(gzReader) } diff --git a/backend/app/migrations/duckdb_telemetry/0002_uuid_columns.up.sql b/backend/app/migrations/duckdb_telemetry/0002_uuid_columns.up.sql new file mode 100644 index 000000000..f6071894f --- /dev/null +++ b/backend/app/migrations/duckdb_telemetry/0002_uuid_columns.up.sql @@ -0,0 +1,15 @@ +ALTER TABLE spans ALTER COLUMN id SET DATA TYPE UUID; +ALTER TABLE spans ALTER COLUMN trace_id SET DATA TYPE UUID; +ALTER TABLE spans ALTER COLUMN project_id SET DATA TYPE UUID; +ALTER TABLE spans ALTER COLUMN parent_span_id SET DATA TYPE UUID; +ALTER TABLE endpoints ALTER COLUMN id SET DATA TYPE UUID; +ALTER TABLE endpoints ALTER COLUMN project_id SET DATA TYPE UUID; +ALTER TABLE endpoints ALTER COLUMN distributed_trace_id SET DATA TYPE UUID; +ALTER TABLE endpoints ALTER COLUMN span_id SET DATA TYPE UUID; +ALTER TABLE tasks ALTER COLUMN id SET DATA TYPE UUID; +ALTER TABLE tasks ALTER COLUMN project_id SET DATA TYPE UUID; +ALTER TABLE tasks ALTER COLUMN distributed_trace_id SET DATA TYPE UUID; +ALTER TABLE tasks ALTER COLUMN span_id SET DATA TYPE UUID; +ALTER TABLE metric_points ALTER COLUMN project_id SET DATA TYPE UUID; +ALTER TABLE log_records ALTER COLUMN id SET DATA TYPE UUID; +ALTER TABLE log_records ALTER COLUMN project_id SET DATA TYPE UUID; diff --git a/backend/app/monitoring/telemetrydb_reporter.go b/backend/app/monitoring/telemetrydb_reporter.go index cc4b04196..a5e93e36e 100644 --- a/backend/app/monitoring/telemetrydb_reporter.go +++ b/backend/app/monitoring/telemetrydb_reporter.go @@ -67,6 +67,15 @@ func reportTelemetryDBOnce(ctx context.Context, b *telemetryDBBaselines) { traceway.CaptureMetric("traceway.duckdb.wal_size_mb", float64(engine.WALSizeBytes)/1024.0/1024.0) traceway.CaptureMetric("traceway.duckdb.memory_used_mb", float64(engine.MemoryUsedBytes)/1024.0/1024.0) traceway.CaptureMetric("traceway.duckdb.read_pool.in_use", float64(engine.ReadPoolInUse)) + + if depths, ok := db.GetTelemetryWriteQueueDepths(); ok { + total := 0 + for table, depth := range depths { + total += depth + traceway.CaptureMetric("traceway.duckdb.write_queue."+table, float64(depth)) + } + traceway.CaptureMetric("traceway.duckdb.write_queue.depth", float64(total)) + } } func safeDeltaInt64(prev, cur int64) int64 { diff --git a/backend/app/notifications/evaluator_helpers.go b/backend/app/notifications/evaluator_helpers.go index bae95702d..36047964f 100644 --- a/backend/app/notifications/evaluator_helpers.go +++ b/backend/app/notifications/evaluator_helpers.go @@ -41,6 +41,22 @@ func evaluateEventRules(event hooks.ReportEvent) { return } + if len(rules) == 0 { + return + } + + // The rules below read back rows the triggering request just ingested + // (exception details, endpoints/tasks by id). On the DuckDB backend those + // inserts sit in the background write queue for up to the flush interval, + // so force a flush first; no-op on the other backends. Bounded so a + // stalled writer degrades the notification content instead of leaking + // this goroutine. + flushCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + if err := telemetry.FlushWriters(flushCtx); err != nil { + traceway.CaptureException(fmt.Errorf("notification evaluator: telemetry flush barrier: %w", err)) + } + cancel() + ctx := context.Background() for _, rule := range rules { diff --git a/backend/app/repositories/telemetry/duckdb/endpoint.repository.go b/backend/app/repositories/telemetry/duckdb/endpoint.repository.go index 42f372fba..940a7513b 100644 --- a/backend/app/repositories/telemetry/duckdb/endpoint.repository.go +++ b/backend/app/repositories/telemetry/duckdb/endpoint.repository.go @@ -5,6 +5,7 @@ package duckdb import ( "context" "database/sql" + "database/sql/driver" "fmt" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/shared" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/sqlitetypes" @@ -12,7 +13,6 @@ import ( "strings" "time" - "github.com/duckdb/duckdb-go/v2" "github.com/google/uuid" "github.com/tracewayapp/lit/v2" "github.com/tracewayapp/traceway/backend/app/db" @@ -115,56 +115,38 @@ func (r *endpoint) toModel() models.Endpoint { // "root" | "non_root"; defaults to "all" (no filter). type endpointRepository struct{} -func (e *endpointRepository) InsertAsync(ctx context.Context, lines []models.Endpoint) error { - if len(lines) == 0 { - return nil - } - - return withAppender(ctx, "endpoints", func(appender *duckdb.Appender) { - - for _, ep := range lines { - attributesJSON, err := attrJSON(ep.Attributes) - if err != nil { - captureDroppedRow("endpoints", err) - continue - } - - var distributedTraceId *string - if ep.DistributedTraceId != nil { - v := ep.DistributedTraceId.String() - distributedTraceId = &v - } - var spanId *string - if ep.SpanId != nil { - v := ep.SpanId.String() - spanId = &v - } - - isStream := boolToInt(ep.IsStream) - isRoot := boolToInt(ep.IsRoot) - - if err := appender.AppendRow( - ep.Id.String(), - ep.ProjectId.String(), - ep.Endpoint, - int64(ep.Duration), - ep.RecordedAt.UTC(), - int64(ep.StatusCode), - int64(ep.BodySize), - ep.ClientIP, - attributesJSON, - ep.AppVersion, - ep.ServerName, - nullableString(distributedTraceId), - nullableString(spanId), - isStream, - isRoot, - ); err != nil { - captureDroppedRow("endpoints", err) - } +func convertEndpoints(lines []models.Endpoint) [][]driver.Value { + rows := make([][]driver.Value, 0, len(lines)) + for _, ep := range lines { + attributesJSON, err := attrJSON(ep.Attributes) + if err != nil { + captureDroppedRow("endpoints", err) + continue } - }) + rows = append(rows, []driver.Value{ + duckUUID(ep.Id), + duckUUID(ep.ProjectId), + ep.Endpoint, + int64(ep.Duration), + ep.RecordedAt.UTC(), + int64(ep.StatusCode), + int64(ep.BodySize), + ep.ClientIP, + attributesJSON, + ep.AppVersion, + ep.ServerName, + nullableUUID(ep.DistributedTraceId), + nullableUUID(ep.SpanId), + boolToInt(ep.IsStream), + boolToInt(ep.IsRoot), + }) + } + return rows +} + +func (e *endpointRepository) InsertAsync(ctx context.Context, lines []models.Endpoint) error { + return insertRows(ctx, "endpoints", convertEndpoints(lines)) } func (e *endpointRepository) CountBetween(ctx context.Context, projectId uuid.UUID, start, end time.Time) (int64, error) { diff --git a/backend/app/repositories/telemetry/duckdb/helpers.go b/backend/app/repositories/telemetry/duckdb/helpers.go index af14e4244..c0f51ffbe 100644 --- a/backend/app/repositories/telemetry/duckdb/helpers.go +++ b/backend/app/repositories/telemetry/duckdb/helpers.go @@ -10,6 +10,7 @@ import ( "time" "github.com/duckdb/duckdb-go/v2" + "github.com/google/uuid" "github.com/tracewayapp/traceway/backend/app/db" traceway "go.tracewayapp.com" ) @@ -24,6 +25,20 @@ func nullableString(s *string) any { return *s } +// duckUUID converts to the driver's native UUID value: a zero-alloc +// [16]byte-to-[16]byte conversion, vs the 36-byte string uuid.String() +// allocates for VARCHAR columns. +func duckUUID(u uuid.UUID) duckdb.UUID { + return duckdb.UUID(u) +} + +func nullableUUID(u *uuid.UUID) any { + if u == nil { + return nil + } + return duckdb.UUID(*u) +} + const dropReportInterval = time.Minute var ( @@ -32,6 +47,29 @@ var ( lastDropReportAt = map[string]time.Time{} ) +// captureFlushFailure reports background-writer connect/flush failures with +// the same 1-minute-per-table rate limit as captureDroppedRow, keyed +// separately so a drop storm can't mask a flush failure. +func captureFlushFailure(table string, lostRows int, err error) { + key := table + ":flush" + + var report bool + dropReportMu.Lock() + if time.Since(lastDropReportAt[key]) >= dropReportInterval { + lastDropReportAt[key] = time.Now() + report = true + } + dropReportMu.Unlock() + + if report { + if lostRows > 0 { + traceway.CaptureException(fmt.Errorf("duckdb %s background writer: %d acked rows lost, latest: %w", table, lostRows, err)) + } else { + traceway.CaptureException(fmt.Errorf("duckdb %s background writer: connect/appender setup failing, no rows lost yet, latest: %w", table, err)) + } + } +} + func captureDroppedRow(table string, err error) { db.RecordTelemetryRowDropped(table) diff --git a/backend/app/repositories/telemetry/duckdb/log_record.repository.go b/backend/app/repositories/telemetry/duckdb/log_record.repository.go index 243a3b195..c2f6fb0c4 100644 --- a/backend/app/repositories/telemetry/duckdb/log_record.repository.go +++ b/backend/app/repositories/telemetry/duckdb/log_record.repository.go @@ -4,12 +4,13 @@ package duckdb import ( "context" + "database/sql/driver" "fmt" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/shared" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/sqlitetypes" + "reflect" "strings" - "github.com/duckdb/duckdb-go/v2" "github.com/google/uuid" "github.com/tracewayapp/lit/v2" @@ -75,54 +76,79 @@ func (r *logRecord) toModel() models.LogRecord { type logRecordRepository struct{} -func (r *logRecordRepository) InsertAsync(ctx context.Context, records []models.LogRecord) error { - if len(records) == 0 { - return nil - } - - return withAppender(ctx, "log_records", func(appender *duckdb.Appender) { +// attrJSONMemo caches the marshal of the last-seen attribute map by map +// identity. The OTLP logs converter builds one resource-attributes map and +// one scope-attributes map per resource/scope and assigns the same map to +// every record under it, so a 16k-record batch otherwise re-marshals an +// identical map 16k times per level. Identity (not content) comparison is +// safe because the converter never mutates the maps after building them. +type attrJSONMemo struct { + last uintptr + lastJSON string + valid bool +} - for _, lr := range records { - resourceJSON, err := attrJSON(lr.ResourceAttributes) - if err != nil { - captureDroppedRow("log_records", err) - continue - } - scopeJSON, err := attrJSON(lr.ScopeAttributes) - if err != nil { - captureDroppedRow("log_records", err) - continue - } - logJSON, err := attrJSON(lr.LogAttributes) - if err != nil { - captureDroppedRow("log_records", err) - continue - } +func (m *attrJSONMemo) json(attrs map[string]string) (string, error) { + if len(attrs) == 0 { + return "{}", nil + } + p := reflect.ValueOf(attrs).Pointer() + if m.valid && p == m.last { + return m.lastJSON, nil + } + s, err := attrJSON(attrs) + if err != nil { + return "", err + } + m.last, m.lastJSON, m.valid = p, s, true + return s, nil +} - if err := appender.AppendRow( - lr.Id.String(), - lr.ProjectId.String(), - lr.Timestamp.UTC(), - lr.TraceId, - lr.SpanId, - int64(lr.TraceFlags), - lr.SeverityText, - int64(lr.SeverityNumber), - lr.ServiceName, - lr.Body, - lr.ResourceSchemaUrl, - resourceJSON, - lr.ScopeSchemaUrl, - lr.ScopeName, - lr.ScopeVersion, - scopeJSON, - logJSON, - ); err != nil { - captureDroppedRow("log_records", err) - } +func convertLogRecords(records []models.LogRecord) [][]driver.Value { + rows := make([][]driver.Value, 0, len(records)) + var resourceMemo, scopeMemo attrJSONMemo + for _, lr := range records { + resourceJSON, err := resourceMemo.json(lr.ResourceAttributes) + if err != nil { + captureDroppedRow("log_records", err) + continue + } + scopeJSON, err := scopeMemo.json(lr.ScopeAttributes) + if err != nil { + captureDroppedRow("log_records", err) + continue + } + logJSON, err := attrJSON(lr.LogAttributes) + if err != nil { + captureDroppedRow("log_records", err) + continue } - }) + rows = append(rows, []driver.Value{ + duckUUID(lr.Id), + duckUUID(lr.ProjectId), + lr.Timestamp.UTC(), + lr.TraceId, + lr.SpanId, + int64(lr.TraceFlags), + lr.SeverityText, + int64(lr.SeverityNumber), + lr.ServiceName, + lr.Body, + lr.ResourceSchemaUrl, + resourceJSON, + lr.ScopeSchemaUrl, + lr.ScopeName, + lr.ScopeVersion, + scopeJSON, + logJSON, + }) + } + return rows +} + +func (r *logRecordRepository) InsertAsync(ctx context.Context, records []models.LogRecord) error { + return insertRows(ctx, "log_records", convertLogRecords(records)) } func (r *logRecordRepository) Search(ctx context.Context, params shared.LogSearchParams) ([]models.LogRecord, int64, error) { diff --git a/backend/app/repositories/telemetry/duckdb/metric_point.repository.go b/backend/app/repositories/telemetry/duckdb/metric_point.repository.go index 5eeba4264..a06a25fe6 100644 --- a/backend/app/repositories/telemetry/duckdb/metric_point.repository.go +++ b/backend/app/repositories/telemetry/duckdb/metric_point.repository.go @@ -5,11 +5,11 @@ package duckdb import ( "context" "database/sql" + "database/sql/driver" "fmt" "strings" "time" - "github.com/duckdb/duckdb-go/v2" "github.com/google/uuid" "github.com/tracewayapp/lit/v2" "github.com/tracewayapp/traceway/backend/app/db" @@ -39,25 +39,21 @@ func init() { }) } -func (r *metricPointRepository) InsertAsync(ctx context.Context, points []models.MetricPoint) error { - if len(points) == 0 { - return nil - } - - return withAppender(ctx, "metric_points", func(appender *duckdb.Appender) { - - for _, p := range points { - tagsJSON, err := attrJSON(p.Tags) - if err != nil { - captureDroppedRow("metric_points", err) - continue - } - if err := appender.AppendRow(p.ProjectId.String(), p.Name, p.Value, tagsJSON, p.RecordedAt.UTC(), p.Tags["server_name"]); err != nil { - captureDroppedRow("metric_points", err) - } +func convertMetricPoints(points []models.MetricPoint) [][]driver.Value { + rows := make([][]driver.Value, 0, len(points)) + for _, p := range points { + tagsJSON, err := attrJSON(p.Tags) + if err != nil { + captureDroppedRow("metric_points", err) + continue } + rows = append(rows, []driver.Value{duckUUID(p.ProjectId), p.Name, p.Value, tagsJSON, p.RecordedAt.UTC(), p.Tags["server_name"]}) + } + return rows +} - }) +func (r *metricPointRepository) InsertAsync(ctx context.Context, points []models.MetricPoint) error { + return insertRows(ctx, "metric_points", convertMetricPoints(points)) } func (r *metricPointRepository) QueryTimeSeries(ctx context.Context, projectId uuid.UUID, name string, from, to time.Time, intervalMinutes int, aggregation string, tagFilters map[string]string, groupBy string) (map[string][]models.TimeSeriesPoint, error) { diff --git a/backend/app/repositories/telemetry/duckdb/span.repository.go b/backend/app/repositories/telemetry/duckdb/span.repository.go index 7f9d5bd7d..e7904ffd0 100644 --- a/backend/app/repositories/telemetry/duckdb/span.repository.go +++ b/backend/app/repositories/telemetry/duckdb/span.repository.go @@ -4,11 +4,11 @@ package duckdb import ( "context" + "database/sql/driver" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/shared" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/sqlitetypes" "time" - "github.com/duckdb/duckdb-go/v2" "github.com/google/uuid" "github.com/tracewayapp/lit/v2" "github.com/tracewayapp/traceway/backend/app/db" @@ -52,42 +52,32 @@ func (r *span) toModel() models.Span { type spanRepository struct{} -func (r *spanRepository) InsertAsync(ctx context.Context, spans []models.Span) error { - if len(spans) == 0 { - return nil - } - - return withAppender(ctx, "spans", func(appender *duckdb.Appender) { - - for _, s := range spans { - attributesJSON, err := attrJSON(s.Attributes) - if err != nil { - captureDroppedRow("spans", err) - continue - } - - var parentSpanId *string - if s.ParentSpanId != nil { - v := s.ParentSpanId.String() - parentSpanId = &v - } - - if err := appender.AppendRow( - s.Id.String(), - s.TraceId.String(), - s.ProjectId.String(), - s.Name, - s.StartTime.UTC(), - int64(s.Duration), - s.RecordedAt.UTC(), - nullableString(parentSpanId), - attributesJSON, - ); err != nil { - captureDroppedRow("spans", err) - } +func convertSpans(spans []models.Span) [][]driver.Value { + rows := make([][]driver.Value, 0, len(spans)) + for _, s := range spans { + attributesJSON, err := attrJSON(s.Attributes) + if err != nil { + captureDroppedRow("spans", err) + continue } - }) + rows = append(rows, []driver.Value{ + duckUUID(s.Id), + duckUUID(s.TraceId), + duckUUID(s.ProjectId), + s.Name, + s.StartTime.UTC(), + int64(s.Duration), + s.RecordedAt.UTC(), + nullableUUID(s.ParentSpanId), + attributesJSON, + }) + } + return rows +} + +func (r *spanRepository) InsertAsync(ctx context.Context, spans []models.Span) error { + return insertRows(ctx, "spans", convertSpans(spans)) } func (r *spanRepository) FindByTraceId(ctx context.Context, projectId, traceId uuid.UUID, recordedAt *time.Time) ([]models.Span, error) { diff --git a/backend/app/repositories/telemetry/duckdb/task.repository.go b/backend/app/repositories/telemetry/duckdb/task.repository.go index 71d30be71..91876da2b 100644 --- a/backend/app/repositories/telemetry/duckdb/task.repository.go +++ b/backend/app/repositories/telemetry/duckdb/task.repository.go @@ -5,6 +5,7 @@ package duckdb import ( "context" "database/sql" + "database/sql/driver" "fmt" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/shared" "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/sqlitetypes" @@ -12,7 +13,6 @@ import ( "strings" "time" - "github.com/duckdb/duckdb-go/v2" "github.com/google/uuid" "github.com/tracewayapp/lit/v2" "github.com/tracewayapp/traceway/backend/app/db" @@ -80,53 +80,35 @@ func (r *task) toModel() models.Task { type taskRepository struct{} -func (e *taskRepository) InsertAsync(ctx context.Context, lines []models.Task) error { - if len(lines) == 0 { - return nil - } - - return withAppender(ctx, "tasks", func(appender *duckdb.Appender) { - - for _, t := range lines { - attributesJSON, err := attrJSON(t.Attributes) - if err != nil { - captureDroppedRow("tasks", err) - continue - } - - var distributedTraceId *string - if t.DistributedTraceId != nil { - s := t.DistributedTraceId.String() - distributedTraceId = &s - } - - var spanId *string - if t.SpanId != nil { - s := t.SpanId.String() - spanId = &s - } - - isRoot := boolToInt(t.IsRoot) - - if err := appender.AppendRow( - t.Id.String(), - t.ProjectId.String(), - t.TaskName, - int64(t.Duration), - t.RecordedAt.UTC(), - t.ClientIP, - attributesJSON, - t.AppVersion, - t.ServerName, - nullableString(distributedTraceId), - nullableString(spanId), - isRoot, - ); err != nil { - captureDroppedRow("tasks", err) - } +func convertTasks(lines []models.Task) [][]driver.Value { + rows := make([][]driver.Value, 0, len(lines)) + for _, t := range lines { + attributesJSON, err := attrJSON(t.Attributes) + if err != nil { + captureDroppedRow("tasks", err) + continue } - }) + rows = append(rows, []driver.Value{ + duckUUID(t.Id), + duckUUID(t.ProjectId), + t.TaskName, + int64(t.Duration), + t.RecordedAt.UTC(), + t.ClientIP, + attributesJSON, + t.AppVersion, + t.ServerName, + nullableUUID(t.DistributedTraceId), + nullableUUID(t.SpanId), + boolToInt(t.IsRoot), + }) + } + return rows +} + +func (e *taskRepository) InsertAsync(ctx context.Context, lines []models.Task) error { + return insertRows(ctx, "tasks", convertTasks(lines)) } func (e *taskRepository) CountBetween(ctx context.Context, projectId uuid.UUID, start, end time.Time) (int64, error) { diff --git a/backend/app/repositories/telemetry/duckdb/writer.go b/backend/app/repositories/telemetry/duckdb/writer.go new file mode 100644 index 000000000..eb77b133c --- /dev/null +++ b/backend/app/repositories/telemetry/duckdb/writer.go @@ -0,0 +1,460 @@ +//go:build telemetry_duckdb + +package duckdb + +import ( + "context" + "database/sql/driver" + "fmt" + "runtime" + "sync" + "sync/atomic" + "time" + + "github.com/duckdb/duckdb-go/v2" + "github.com/tracewayapp/traceway/backend/app/db" + traceway "go.tracewayapp.com" +) + +// The per-request appender path (one connection + one WAL commit per ingest +// request) is what capped write throughput in the benchmarks: at the cliff a +// 16k-row request held an admission slot for 1-3s. The writers below decouple +// the request path from the flush: requests convert rows and enqueue, one +// goroutine per hot table owns a persistent connection + Appender and flushes +// on a size-or-age trigger, coalescing many request batches into one WAL +// commit. A 200 therefore means "accepted into the bounded write queue", not +// "committed" — the same semantics the OTel Collector and its sending queue +// give. The queue is bounded and enqueue rejects with ErrIngestQueueFull +// (mapped to 503 + Retry-After) so overload is shed before the ack, never by +// dropping acked rows. +const ( + defaultWriteQueueRows = 131072 + defaultWriteFlushRows = 32768 + defaultWriteFlushInterval = 100 * time.Millisecond + + // How long enqueue waits for queue space before the 503. VictoriaMetrics + // queues inserts up to a full minute (insert.maxQueueDuration); without a + // wait, sub-second ingest bursts overrun the queue and turn into 503s at + // rates the writers sustain on average (v2 benchmarks: every failing + // step showed 5-10% instant rejects while drain kept up). + defaultWriteQueueWait = 2 * time.Second + writeQueueWaitPoll = 10 * time.Millisecond + + writerReconnectMinBackoff = 100 * time.Millisecond + writerReconnectMaxBackoff = 5 * time.Second +) + +var batchedTables = []string{"spans", "metric_points", "log_records", "endpoints", "tasks"} + +type writeReq struct { + rows [][]driver.Value + // done non-nil marks a flush barrier: the writer flushes everything + // enqueued before it (channel FIFO) and closes the channel. rows is nil. + done chan struct{} +} + +// tableWriter owns one table's queue, sharded across a small pool of writer +// goroutines (VictoriaMetrics-style: drain concurrency sized to CPU). Each +// goroutine owns one channel and one connection + Appender exclusively — the +// duckdb Appender is not thread-safe; all cross-goroutine interaction goes +// through the channels. Batches are round-robined across the shards, so +// per-channel FIFO still guarantees a barrier sent to every shard flushes +// everything enqueued before it. +type tableWriter struct { + table string + chans []chan writeReq + next atomic.Uint64 + maxQueueRows int64 + flushRows int + flushInterval time.Duration + queueWait time.Duration + + // pendingRows counts rows admitted but not yet flushed (queued + + // appended-unflushed). It is decremented after the flush, not after the + // append, so it is simultaneously the backpressure bound, the + // acked-but-unpersisted loss window, and the queue-depth gauge: a stalled + // WAL commit keeps it high and enqueue keeps rejecting. Do not "fix" it + // to decrement at append time. + pendingRows atomic.Int64 + enqueuedRows atomic.Uint64 + flushedRows atomic.Uint64 + flushErrors atomic.Uint64 +} + +type writerSet struct { + byTable map[string]*tableWriter + cancel context.CancelFunc + wg sync.WaitGroup +} + +var activeWriters atomic.Pointer[writerSet] + +type WriterOptions struct { + QueueRows int + FlushRows int + FlushInterval time.Duration + Writers int + // QueueWait is how long enqueue blocks for space before rejecting. + // Zero means the default; negative disables the wait (tests). + QueueWait time.Duration +} + +// defaultWritersPerTable mirrors the admission gate's old concurrency +// (2×CPU), which is also VictoriaMetrics' default insert concurrency — the +// single-writer v1 measurably under-drained bulk ingest vs the old +// per-request appenders. +func defaultWritersPerTable() int { + n := runtime.NumCPU() * 2 + if n < 2 { + n = 2 + } + if n > 8 { + n = 8 + } + return n +} + +// StartWriters starts one background writer per batched table. Idempotent. +func StartWriters(ctx context.Context, opts WriterOptions) { + if activeWriters.Load() != nil { + return + } + if opts.QueueRows <= 0 { + opts.QueueRows = defaultWriteQueueRows + } + if opts.FlushRows <= 0 { + opts.FlushRows = defaultWriteFlushRows + } + if opts.FlushInterval <= 0 { + opts.FlushInterval = defaultWriteFlushInterval + } + if opts.Writers <= 0 { + opts.Writers = defaultWritersPerTable() + } + if opts.QueueWait == 0 { + opts.QueueWait = defaultWriteQueueWait + } + if opts.QueueWait > 0 { + db.SetIngestQueueRetryAfter(opts.QueueWait) + } + + // Derive a cancelable context so StopWriters works even though the + // server passes context.Background(). + ctx, cancel := context.WithCancel(ctx) + ws := &writerSet{byTable: make(map[string]*tableWriter, len(batchedTables)), cancel: cancel} + for _, table := range batchedTables { + w := &tableWriter{ + table: table, + chans: make([]chan writeReq, opts.Writers), + maxQueueRows: int64(opts.QueueRows), + flushRows: opts.FlushRows, + flushInterval: opts.FlushInterval, + queueWait: opts.QueueWait, + } + for i := range w.chans { + // Every data batch carries >=1 row, so admitted batches <= + // admitted rows <= maxQueueRows regardless of how round-robin + // distributes them; the slack absorbs concurrent zero-row + // barriers. An admitted send therefore never blocks. + w.chans[i] = make(chan writeReq, opts.QueueRows+16) + ws.wg.Add(1) + go w.runLoop(ctx, w.chans[i], &ws.wg) + } + ws.byTable[table] = w + } + if !activeWriters.CompareAndSwap(nil, ws) { + cancel() + ws.wg.Wait() + return + } + db.SetTelemetryWriteQueueDepthFn(func() map[string]int { + depths := make(map[string]int, len(batchedTables)) + if cur := activeWriters.Load(); cur != nil { + for table, w := range cur.byTable { + depths[table] = int(w.pendingRows.Load()) + } + } + return depths + }) +} + +// StopWriters flushes and stops all writers. Needed by tests, which swap the +// global DuckDB connector between cases. +func StopWriters() { + ws := activeWriters.Swap(nil) + if ws == nil { + return + } + ws.cancel() + ws.wg.Wait() + db.SetTelemetryWriteQueueDepthFn(nil) +} + +// FlushWriters blocks until every row enqueued before the call is flushed to +// DuckDB. Used by the notification evaluator (which reads back rows it just +// ingested) and by tests. No-op when writers are not running. +func FlushWriters(ctx context.Context) error { + ws := activeWriters.Load() + if ws == nil { + return nil + } + var barriers []chan struct{} + for _, w := range ws.byTable { + for _, ch := range w.chans { + done := make(chan struct{}) + select { + case ch <- writeReq{done: done}: + barriers = append(barriers, done) + case <-ctx.Done(): + return ctx.Err() + } + } + } + for _, done := range barriers { + select { + case <-done: + case <-ctx.Done(): + return ctx.Err() + } + } + return nil +} + +// insertRows is the shared entry for the batched tables: enqueue when the +// writers are running, otherwise fall back to the synchronous per-request +// appender path (tests, and any deployment that never starts the writers). +func insertRows(ctx context.Context, table string, rows [][]driver.Value) error { + if len(rows) == 0 { + return nil + } + if ws := activeWriters.Load(); ws != nil { + if w, ok := ws.byTable[table]; ok { + return w.enqueue(ctx, rows) + } + } + return appendRowsSync(ctx, table, rows) +} + +func appendRowsSync(ctx context.Context, table string, rows [][]driver.Value) error { + return withAppender(ctx, table, func(appender *duckdb.Appender) { + for _, row := range rows { + if err := appender.AppendRow(row...); err != nil { + captureDroppedRow(table, err) + } + } + }) +} + +func (w *tableWriter) enqueue(ctx context.Context, rows [][]driver.Value) error { + n := int64(len(rows)) + if w.admit(n) { + w.send(rows, n) + return nil + } + if w.queueWait <= 0 { + return db.ErrIngestQueueFull + } + // The queue is a fraction of a second deep at peak rates; waiting briefly + // absorbs ingest bursts that the writers sustain on average, and costs no + // extra memory (the decoded batch exists either way, bounded upstream by + // the admission gate). Only a genuinely stalled writer still 503s. + deadline := time.Now().Add(w.queueWait) + poll := time.NewTimer(writeQueueWaitPoll) + defer poll.Stop() + for { + select { + case <-ctx.Done(): + return ctx.Err() + case <-poll.C: + } + if w.admit(n) { + w.send(rows, n) + return nil + } + if time.Now().After(deadline) { + return db.ErrIngestQueueFull + } + poll.Reset(writeQueueWaitPoll) + } +} + +func (w *tableWriter) admit(n int64) bool { + if w.pendingRows.Add(n) > w.maxQueueRows { + w.pendingRows.Add(-n) + return false + } + return true +} + +func (w *tableWriter) send(rows [][]driver.Value, n int64) { + w.enqueuedRows.Add(uint64(n)) + w.chans[w.next.Add(1)%uint64(len(w.chans))] <- writeReq{rows: rows} +} + +// runLoop restarts runOnce after a panic instead of dying: a dead writer +// would strand its shard of the queue into permanent 503s for the table. +func (w *tableWriter) runLoop(ctx context.Context, ch chan writeReq, wg *sync.WaitGroup) { + defer wg.Done() + for { + if done := w.runOnce(ctx, ch); done { + return + } + select { + case <-ctx.Done(): + return + case <-time.After(writerReconnectMinBackoff): + } + } +} + +func (w *tableWriter) runOnce(ctx context.Context, ch chan writeReq) (done bool) { + var ( + conn driver.Conn + appender *duckdb.Appender + sinceFlush int + barrier chan struct{} + ) + defer func() { + if r := recover(); r != nil { + traceway.CaptureException(fmt.Errorf("duckdb %s writer panic: %v", w.table, r)) + if sinceFlush > 0 { + w.dropUnflushed(sinceFlush, fmt.Errorf("writer panic: %v", r)) + } + if appender != nil { + // The unflushed rows were just counted as dropped; Clear so + // the deferred Close below can't half-commit them. + appender.Clear() + } + if barrier != nil { + // Left open, FlushWriters would hang until its ctx deadline. + close(barrier) + } + done = false + } + if appender != nil { + appender.Close() + } + if conn != nil { + conn.Close() + } + }() + + ensure := func() bool { + backoff := writerReconnectMinBackoff + for appender == nil { + var err error + conn, err = db.DuckDBConnector.Connect(ctx) + if err == nil { + appender, err = duckdb.NewAppenderFromConn(conn, "", w.table) + if err == nil { + return true + } + conn.Close() + conn = nil + } + db.RecordTelemetryInsertFailure() + captureFlushFailure(w.table, 0, err) + select { + case <-ctx.Done(): + return false + case <-time.After(backoff): + } + backoff *= 2 + if backoff > writerReconnectMaxBackoff { + backoff = writerReconnectMaxBackoff + } + } + return true + } + + flush := func() { + if appender == nil || sinceFlush == 0 { + return + } + if err := appender.Flush(); err != nil { + // The rows in this appender chunk were already acked. Clear and + // drop them (counted), close the connection, and let ensure() + // reconnect with backoff; rows still in the channel survive. + w.flushErrors.Add(1) + db.RecordTelemetryInsertFailure() + w.dropUnflushed(sinceFlush, err) + appender.Clear() + appender.Close() + conn.Close() + appender = nil + conn = nil + } else { + w.flushedRows.Add(uint64(sinceFlush)) + w.pendingRows.Add(-int64(sinceFlush)) + } + sinceFlush = 0 + } + + timer := time.NewTimer(w.flushInterval) + if !timer.Stop() { + <-timer.C + } + timerActive := false + defer timer.Stop() + + for { + select { + case <-ctx.Done(): + // Best-effort final flush so StopWriters (tests) doesn't lose + // rows. In production nothing cancels this context. + flush() + return true + case req := <-ch: + if req.done != nil { + barrier = req.done + flush() + if timerActive { + if !timer.Stop() { + <-timer.C + } + timerActive = false + } + close(req.done) + barrier = nil + continue + } + if !ensure() { + // Shutdown while reconnecting: the admitted rows are dropped + // with the process; nothing to flush. + w.dropUnflushed(len(req.rows), ctx.Err()) + return true + } + // Counted before the append loop so a panic mid-append settles + // these rows in the recover instead of leaking queue budget. + sinceFlush += len(req.rows) + for _, row := range req.rows { + if err := appender.AppendRow(row...); err != nil { + captureDroppedRow(w.table, err) + } + } + if sinceFlush >= w.flushRows { + flush() + if timerActive { + if !timer.Stop() { + <-timer.C + } + timerActive = false + } + } else if !timerActive { + timer.Reset(w.flushInterval) + timerActive = true + } + case <-timer.C: + timerActive = false + flush() + } + } +} + +// dropUnflushed settles n admitted-but-lost rows: releases their queue budget +// and records them as dropped (they may have been acked already). +func (w *tableWriter) dropUnflushed(n int, err error) { + w.pendingRows.Add(-int64(n)) + db.RecordTelemetryRowsDropped(w.table, uint64(n)) + captureFlushFailure(w.table, n, err) +} diff --git a/backend/app/repositories/telemetry/duckdb/writer_test.go b/backend/app/repositories/telemetry/duckdb/writer_test.go new file mode 100644 index 000000000..7df39fedf --- /dev/null +++ b/backend/app/repositories/telemetry/duckdb/writer_test.go @@ -0,0 +1,72 @@ +//go:build telemetry_duckdb + +package duckdb + +import ( + "context" + "database/sql" + "database/sql/driver" + "testing" + "time" + + "github.com/duckdb/duckdb-go/v2" + "github.com/tracewayapp/traceway/backend/app/db" +) + +func TestWriterPoisonRowDropped(t *testing.T) { + connector, err := duckdb.NewConnector("", nil) + if err != nil { + t.Fatalf("failed to open in-memory duckdb: %v", err) + } + sqlDB := sql.OpenDB(connector) + t.Cleanup(func() { sqlDB.Close() }) + + if _, err := sqlDB.Exec(`CREATE TABLE spans ( + id VARCHAR NOT NULL, + trace_id VARCHAR NOT NULL, + project_id VARCHAR NOT NULL, + name VARCHAR NOT NULL DEFAULT '', + start_time TIMESTAMP NOT NULL, + duration BIGINT NOT NULL DEFAULT 0, + recorded_at TIMESTAMP NOT NULL, + parent_span_id VARCHAR, + attributes VARCHAR NOT NULL DEFAULT '{}' + )`); err != nil { + t.Fatalf("failed to create spans table: %v", err) + } + + prevConnector, prevDB := db.DuckDBConnector, db.TelemetryDB + db.DuckDBConnector = connector + db.TelemetryDB = sqlDB + t.Cleanup(func() { db.DuckDBConnector, db.TelemetryDB = prevConnector, prevDB }) + + StartWriters(context.Background(), WriterOptions{FlushRows: 1 << 20, FlushInterval: time.Hour}) + t.Cleanup(StopWriters) + + _, droppedBefore, _ := db.GetTelemetryIngestCounters() + + ctx := context.Background() + now := time.Now().UTC() + good := []driver.Value{"id-1", "trace-1", "project-1", "ok", now, int64(1), now, nil, "{}"} + poison := []driver.Value{struct{}{}, "trace-1", "project-1", "bad", now, int64(1), now, nil, "{}"} + + if err := insertRows(ctx, "spans", [][]driver.Value{good, poison}); err != nil { + t.Fatalf("insertRows failed: %v", err) + } + if err := FlushWriters(ctx); err != nil { + t.Fatalf("FlushWriters failed: %v", err) + } + + var count int + if err := sqlDB.QueryRow("SELECT COUNT(*) FROM spans").Scan(&count); err != nil { + t.Fatalf("count query failed: %v", err) + } + if count != 1 { + t.Fatalf("expected 1 flushed row (poison dropped), got %d", count) + } + + _, droppedAfter, _ := db.GetTelemetryIngestCounters() + if droppedAfter != droppedBefore+1 { + t.Fatalf("expected dropped counter to grow by 1, went %d -> %d", droppedBefore, droppedAfter) + } +} diff --git a/backend/app/repositories/telemetry/metric_point.repository_duckdb_test.go b/backend/app/repositories/telemetry/metric_point.repository_duckdb_test.go index 0bfe77f11..29b28d34f 100644 --- a/backend/app/repositories/telemetry/metric_point.repository_duckdb_test.go +++ b/backend/app/repositories/telemetry/metric_point.repository_duckdb_test.go @@ -23,7 +23,7 @@ func setupDuckDB(t *testing.T) { } telemetry := sql.OpenDB(connector) if _, err := telemetry.Exec(`CREATE TABLE metric_points ( - project_id VARCHAR NOT NULL, + project_id UUID NOT NULL, name VARCHAR NOT NULL DEFAULT '', value DOUBLE NOT NULL DEFAULT 0, tags VARCHAR NOT NULL DEFAULT '{}', diff --git a/backend/app/repositories/telemetry/telemetry_ch.go b/backend/app/repositories/telemetry/telemetry_ch.go index 0d51cabdb..ba16a768b 100644 --- a/backend/app/repositories/telemetry/telemetry_ch.go +++ b/backend/app/repositories/telemetry/telemetry_ch.go @@ -2,7 +2,11 @@ package telemetry -import ch "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/clickhouse" +import ( + "context" + + ch "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/clickhouse" +) var ( AiTraceRepository = ch.AiTraceRepository @@ -17,3 +21,11 @@ var ( SpanRepository = ch.SpanRepository TaskRepository = ch.TaskRepository ) + +// StartWriters is a no-op: ClickHouse batch inserts are already efficient +// per request. +func StartWriters(ctx context.Context) {} + +// FlushWriters is a no-op: ClickHouse inserts are visible when InsertAsync +// returns. +func FlushWriters(ctx context.Context) error { return nil } diff --git a/backend/app/repositories/telemetry/telemetry_duckdb.go b/backend/app/repositories/telemetry/telemetry_duckdb.go index 194736514..3e70b0cfb 100644 --- a/backend/app/repositories/telemetry/telemetry_duckdb.go +++ b/backend/app/repositories/telemetry/telemetry_duckdb.go @@ -2,7 +2,15 @@ package telemetry -import duckdbrepo "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/duckdb" +import ( + "context" + "strconv" + "strings" + "time" + + "github.com/tracewayapp/traceway/backend/app/config" + duckdbrepo "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/duckdb" +) var ( AiTraceRepository = duckdbrepo.AiTraceRepository @@ -17,3 +25,34 @@ var ( SpanRepository = duckdbrepo.SpanRepository TaskRepository = duckdbrepo.TaskRepository ) + +// StartWriters starts the DuckDB background write batchers for the hot +// telemetry tables. Invalid or unset env values fall back to the writer +// defaults (zero values in WriterOptions). +func StartWriters(ctx context.Context) { + opts := duckdbrepo.WriterOptions{ + QueueRows: parsePositiveInt(config.Config.DuckDBWriteQueueRows), + FlushRows: parsePositiveInt(config.Config.DuckDBWriteFlushRows), + Writers: parsePositiveInt(config.Config.DuckDBWriteWriters), + } + if ms := parsePositiveInt(config.Config.DuckDBWriteFlushIntervalMS); ms > 0 { + opts.FlushInterval = time.Duration(ms) * time.Millisecond + } + if ms := parsePositiveInt(config.Config.DuckDBWriteQueueWaitMS); ms > 0 { + opts.QueueWait = time.Duration(ms) * time.Millisecond + } + duckdbrepo.StartWriters(ctx, opts) +} + +// FlushWriters blocks until everything enqueued before the call is flushed. +func FlushWriters(ctx context.Context) error { + return duckdbrepo.FlushWriters(ctx) +} + +func parsePositiveInt(v string) int { + n, err := strconv.Atoi(strings.TrimSpace(v)) + if err != nil || n <= 0 { + return 0 + } + return n +} diff --git a/backend/app/repositories/telemetry/telemetry_sqlite.go b/backend/app/repositories/telemetry/telemetry_sqlite.go index c83a87849..f648ad927 100644 --- a/backend/app/repositories/telemetry/telemetry_sqlite.go +++ b/backend/app/repositories/telemetry/telemetry_sqlite.go @@ -2,7 +2,11 @@ package telemetry -import sqliterepo "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/sqlite" +import ( + "context" + + sqliterepo "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/sqlite" +) var ( AiTraceRepository = sqliterepo.AiTraceRepository @@ -17,3 +21,9 @@ var ( SpanRepository = sqliterepo.SpanRepository TaskRepository = sqliterepo.TaskRepository ) + +// StartWriters is a no-op: the SQLite backend inserts synchronously. +func StartWriters(ctx context.Context) {} + +// FlushWriters is a no-op: SQLite inserts are visible when InsertAsync returns. +func FlushWriters(ctx context.Context) error { return nil } diff --git a/backend/app/repositories/telemetry/writer_duckdb_test.go b/backend/app/repositories/telemetry/writer_duckdb_test.go new file mode 100644 index 000000000..c83cc9930 --- /dev/null +++ b/backend/app/repositories/telemetry/writer_duckdb_test.go @@ -0,0 +1,157 @@ +//go:build telemetry_duckdb + +package telemetry + +import ( + "context" + "errors" + "testing" + "time" + + "github.com/google/uuid" + "github.com/tracewayapp/traceway/backend/app/db" + "github.com/tracewayapp/traceway/backend/app/models" + duckdbrepo "github.com/tracewayapp/traceway/backend/app/repositories/telemetry/duckdb" +) + +func startTestWriters(t *testing.T, opts duckdbrepo.WriterOptions) { + t.Helper() + duckdbrepo.StartWriters(context.Background(), opts) + t.Cleanup(duckdbrepo.StopWriters) +} + +func TestWriterBarrierReadYourWrites(t *testing.T) { + setupTestDB(t) + // Huge thresholds so only the barrier can flush. + startTestWriters(t, duckdbrepo.WriterOptions{FlushRows: 1 << 20, FlushInterval: time.Hour}) + + ctx := context.Background() + projectId := uuid.New() + traceId := uuid.New() + now := truncateMs(time.Now().UTC()) + + err := SpanRepository.InsertAsync(ctx, []models.Span{ + makeSpan(projectId, traceId, "db.query", now, 100*time.Millisecond), + makeSpan(projectId, traceId, "http.request", now.Add(10*time.Millisecond), 200*time.Millisecond), + }) + if err != nil { + t.Fatalf("InsertAsync failed: %v", err) + } + + if err := duckdbrepo.FlushWriters(ctx); err != nil { + t.Fatalf("FlushWriters failed: %v", err) + } + + found, err := SpanRepository.FindByTraceId(ctx, projectId, traceId, nil) + if err != nil { + t.Fatalf("FindByTraceId failed: %v", err) + } + if len(found) != 2 { + t.Fatalf("expected 2 spans after barrier, got %d", len(found)) + } +} + +func TestWriterAgeFlush(t *testing.T) { + setupTestDB(t) + startTestWriters(t, duckdbrepo.WriterOptions{FlushRows: 1 << 20, FlushInterval: 20 * time.Millisecond}) + + ctx := context.Background() + projectId := uuid.New() + traceId := uuid.New() + now := truncateMs(time.Now().UTC()) + + err := SpanRepository.InsertAsync(ctx, []models.Span{ + makeSpan(projectId, traceId, "db.query", now, 100*time.Millisecond), + }) + if err != nil { + t.Fatalf("InsertAsync failed: %v", err) + } + + deadline := time.Now().Add(5 * time.Second) + for { + found, err := SpanRepository.FindByTraceId(ctx, projectId, traceId, nil) + if err != nil { + t.Fatalf("FindByTraceId failed: %v", err) + } + if len(found) == 1 { + return + } + if time.Now().After(deadline) { + t.Fatalf("span not visible after 5s despite 20ms flush interval") + } + time.Sleep(10 * time.Millisecond) + } +} + +func TestWriterQueueFull(t *testing.T) { + setupTestDB(t) + // Negative QueueWait disables the bounded wait so the rejection is + // deterministic and immediate. + startTestWriters(t, duckdbrepo.WriterOptions{QueueRows: 10, FlushRows: 1 << 20, FlushInterval: time.Hour, QueueWait: -1}) + + ctx := context.Background() + projectId := uuid.New() + traceId := uuid.New() + now := truncateMs(time.Now().UTC()) + + spans := func(n int) []models.Span { + out := make([]models.Span, 0, n) + for i := 0; i < n; i++ { + out = append(out, makeSpan(projectId, traceId, "s", now.Add(time.Duration(i)*time.Millisecond), time.Millisecond)) + } + return out + } + + if err := SpanRepository.InsertAsync(ctx, spans(8)); err != nil { + t.Fatalf("expected first batch to be admitted, got %v", err) + } + err := SpanRepository.InsertAsync(ctx, spans(5)) + if !errors.Is(err, db.ErrIngestQueueFull) { + t.Fatalf("expected ErrIngestQueueFull, got %v", err) + } + + // Draining the queue frees the budget; nothing admitted was lost. + if err := duckdbrepo.FlushWriters(ctx); err != nil { + t.Fatalf("FlushWriters failed: %v", err) + } + if err := SpanRepository.InsertAsync(ctx, spans(5)); err != nil { + t.Fatalf("expected insert after drain to succeed, got %v", err) + } + if err := duckdbrepo.FlushWriters(ctx); err != nil { + t.Fatalf("FlushWriters failed: %v", err) + } + + found, err := SpanRepository.FindByTraceId(ctx, projectId, traceId, nil) + if err != nil { + t.Fatalf("FindByTraceId failed: %v", err) + } + if len(found) != 13 { + t.Fatalf("expected 13 spans (8 admitted + 5 after drain), got %d", len(found)) + } +} + +// Pins the synchronous fallback: with no writers started, InsertAsync must be +// immediately visible, which is what the rest of the test suite relies on. +func TestWriterFallbackWhenNotStarted(t *testing.T) { + setupTestDB(t) + + ctx := context.Background() + projectId := uuid.New() + traceId := uuid.New() + now := truncateMs(time.Now().UTC()) + + err := SpanRepository.InsertAsync(ctx, []models.Span{ + makeSpan(projectId, traceId, "db.query", now, 100*time.Millisecond), + }) + if err != nil { + t.Fatalf("InsertAsync failed: %v", err) + } + + found, err := SpanRepository.FindByTraceId(ctx, projectId, traceId, nil) + if err != nil { + t.Fatalf("FindByTraceId failed: %v", err) + } + if len(found) != 1 { + t.Fatalf("expected immediate visibility without writers, got %d spans", len(found)) + } +} diff --git a/backend/cmd/run.go b/backend/cmd/run.go index 49ac7feb6..3aa5bce31 100644 --- a/backend/cmd/run.go +++ b/backend/cmd/run.go @@ -5,6 +5,7 @@ import ( "fmt" "io/fs" "net/http" + _ "net/http/pprof" "os" "strconv" "strings" @@ -21,6 +22,7 @@ import ( "github.com/tracewayapp/traceway/backend/app/monitoring" "github.com/tracewayapp/traceway/backend/app/notifications" "github.com/tracewayapp/traceway/backend/app/recordings" + "github.com/tracewayapp/traceway/backend/app/repositories/telemetry" "github.com/tracewayapp/traceway/backend/app/retention" "github.com/tracewayapp/traceway/backend/app/services" "github.com/tracewayapp/traceway/backend/app/services/mcpmount" @@ -151,11 +153,24 @@ func Run(opts ...Option) { hook(ctx) } + telemetry.StartWriters(ctx) notifications.StartEvaluator(ctx) retention.Start(ctx) recordings.Start(ctx) sourcemapbackfill.Start(ctx) + // Opt-in pprof for profiling ingest under load. Localhost only; gin does + // not use http.DefaultServeMux, so the pprof handlers are unreachable + // through the public router. + if pprofPort := strings.TrimSpace(cfg.PprofPort); pprofPort != "" { + go func() { + defer traceway.Recover() + if err := http.ListenAndServe("127.0.0.1:"+pprofPort, nil); err != nil { + traceway.CaptureException(fmt.Errorf("pprof server on port %s: %w", pprofPort, err)) + } + }() + } + var router *gin.Engine if o != nil && o.disableLogging { router = gin.New() diff --git a/benchmarks/results-probe/ccx13-duckdb-logs-read-probe.json b/benchmarks/results-probe/ccx13-duckdb-logs-read-probe.json new file mode 100644 index 000000000..673e853a1 --- /dev/null +++ b/benchmarks/results-probe/ccx13-duckdb-logs-read-probe.json @@ -0,0 +1,163 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "logs", + "scenario": "read-probe", + "startedAt": "2026-07-24T07:08:18Z", + "endedAt": "2026-07-24T07:35:14Z", + "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": 100000, + "rowsIngested": 860160, + "ingestSecondsElapsed": 10.284488266, + "digestSeconds": 10.010839665, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 161.930609, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 45.294743, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 1.836661, + "ok": true + } + ], + "medianLatencyMs": 45.294743, + "readLatencyMs": 45.294743, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 1000000, + "rowsIngested": 1982464, + "ingestSecondsElapsed": 16.603927069, + "digestSeconds": 10.021487783, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 310.02153599999997, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 37.279258000000006, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 1.675094, + "ok": true + } + ], + "medianLatencyMs": 37.279258000000006, + "readLatencyMs": 37.279258000000006, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 10575872, + "ingestSecondsElapsed": 120.92213144, + "digestSeconds": 10.033132091, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 2340.358738, + "ok": true + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 54.919812, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.161792, + "ok": true + } + ], + "medianLatencyMs": 54.919812, + "readLatencyMs": 54.919812, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 100818944, + "ingestSecondsElapsed": 1378.444149747, + "digestSeconds": 10.010531669, + "probes": [ + { + "name": "logs-severity-error", + "path": "/api/logs", + "latencyMs": 6001.397641, + "ok": false, + "error": "Post \"http://10.0.0.2/api/logs?projectId=8354fa5e-1f66-4f03-a87d-f5734bb94ee1\": context deadline exceeded" + }, + { + "name": "logs-body-search", + "path": "/api/logs", + "latencyMs": 916.395172, + "ok": true + }, + { + "name": "logs-trace-id", + "path": "/api/logs", + "latencyMs": 2.3858040000000003, + "ok": true + } + ], + "medianLatencyMs": 916.395172, + "readLatencyMs": 916.395172, + "readOk": false, + "passed": false, + "failReason": "probe logs-severity-error failed: Post \"http://10.0.0.2/api/logs?projectId=8354fa5e-1f66-4f03-a87d-f5734bb94ee1\": context deadline exceeded (latency 6001ms)" + } + ], + "maxFillLevelPassed": 10000000 + }, + "maxFillLevelPassed": 10000000, + "bytesOnDisk": 9545543680, + "storedRows": 100818944, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/results-probe/ccx13-duckdb-metrics-read-probe.json b/benchmarks/results-probe/ccx13-duckdb-metrics-read-probe.json new file mode 100644 index 000000000..5dbc20783 --- /dev/null +++ b/benchmarks/results-probe/ccx13-duckdb-metrics-read-probe.json @@ -0,0 +1,161 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "metrics", + "scenario": "read-probe", + "startedAt": "2026-07-24T06:55:24Z", + "endedAt": "2026-07-24T07:01:38Z", + "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": 100000, + "rowsIngested": 335872, + "ingestSecondsElapsed": 0.849677645, + "digestSeconds": 10.011681824, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 67.58833899999999, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 42.685781999999996, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 53.966068, + "ok": true + } + ], + "medianLatencyMs": 53.966068, + "readLatencyMs": 53.966068, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 1000000, + "rowsIngested": 2629632, + "ingestSecondsElapsed": 6.2909816020000004, + "digestSeconds": 10.008245742, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 106.77756400000001, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 94.885837, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 151.901535, + "ok": true + } + ], + "medianLatencyMs": 106.77756400000001, + "readLatencyMs": 106.77756400000001, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 11911168, + "ingestSecondsElapsed": 25.483391737, + "digestSeconds": 10.009067168, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 284.146654, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 314.309554, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 525.838686, + "ok": true + } + ], + "medianLatencyMs": 314.309554, + "readLatencyMs": 314.309554, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 101859328, + "ingestSecondsElapsed": 250.727120699, + "digestSeconds": 10.012139145, + "probes": [ + { + "name": "metrics-server", + "path": "/api/metrics/server", + "latencyMs": 1981.1406570000001, + "ok": true + }, + { + "name": "metrics-application", + "path": "/api/metrics/application", + "latencyMs": 2490.6079640000003, + "ok": true + }, + { + "name": "dashboard", + "path": "/api/dashboard", + "latencyMs": 4066.8014780000003, + "ok": true + } + ], + "medianLatencyMs": 2490.6079640000003, + "readLatencyMs": 2490.6079640000003, + "readOk": true, + "passed": true + } + ], + "maxFillLevelPassed": 100000000 + }, + "maxFillLevelPassed": 100000000, + "bytesOnDisk": 1244991488, + "storedRows": 101859328, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/results-probe/ccx13-duckdb-spans-read-probe.json b/benchmarks/results-probe/ccx13-duckdb-spans-read-probe.json new file mode 100644 index 000000000..cebed655f --- /dev/null +++ b/benchmarks/results-probe/ccx13-duckdb-spans-read-probe.json @@ -0,0 +1,165 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "spans", + "scenario": "read-probe", + "startedAt": "2026-07-24T06:34:58Z", + "endedAt": "2026-07-24T06:47:16Z", + "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": 100000, + "rowsIngested": 671744, + "ingestSecondsElapsed": 3.639028536, + "digestSeconds": 10.009535806, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 98.733878, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 65.216915, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 2.55122, + "ok": true + } + ], + "medianLatencyMs": 65.216915, + "readLatencyMs": 65.216915, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 1000000, + "rowsIngested": 2457600, + "ingestSecondsElapsed": 13.458188273, + "digestSeconds": 10.023201221, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 212.992905, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 167.644351, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 9.198341000000001, + "ok": true + } + ], + "medianLatencyMs": 167.644351, + "readLatencyMs": 167.644351, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 10000000, + "rowsIngested": 10878976, + "ingestSecondsElapsed": 61.095033573, + "digestSeconds": 10.008780658, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 751.638382, + "ok": true + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 636.684436, + "ok": true + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 3.183165, + "ok": true + } + ], + "medianLatencyMs": 636.684436, + "readLatencyMs": 636.684436, + "readOk": true, + "passed": true + }, + { + "fillLevelTarget": 100000000, + "rowsIngested": 101023744, + "ingestSecondsElapsed": 559.901757392, + "digestSeconds": 10.008340557, + "probes": [ + { + "name": "endpoints-grouped", + "path": "/api/endpoints/grouped", + "latencyMs": 6001.364783999999, + "ok": false, + "error": "Post \"http://10.0.0.2/api/endpoints/grouped?projectId=199f3158-18b9-4c5a-b03c-2cfc2243891d\": context deadline exceeded" + }, + { + "name": "endpoints-chart", + "path": "/api/endpoints/chart", + "latencyMs": 6005.219403, + "ok": false, + "error": "Post \"http://10.0.0.2/api/endpoints/chart?projectId=199f3158-18b9-4c5a-b03c-2cfc2243891d\": context deadline exceeded" + }, + { + "name": "exception-stack-traces", + "path": "/api/exception-stack-traces", + "latencyMs": 6005.195316, + "ok": false, + "error": "Post \"http://10.0.0.2/api/exception-stack-traces?projectId=199f3158-18b9-4c5a-b03c-2cfc2243891d\": context deadline exceeded" + } + ], + "medianLatencyMs": 6005.195316, + "readLatencyMs": 6005.195316, + "readOk": false, + "passed": false, + "failReason": "probe endpoints-grouped failed: Post \"http://10.0.0.2/api/endpoints/grouped?projectId=199f3158-18b9-4c5a-b03c-2cfc2243891d\": context deadline exceeded (latency 6001ms)" + } + ], + "maxFillLevelPassed": 10000000 + }, + "maxFillLevelPassed": 10000000, + "bytesOnDisk": 5220483072, + "storedRows": 101023744, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 1 + } +} diff --git a/benchmarks/results-probe/chart-readprobe-cliff-logs.png b/benchmarks/results-probe/chart-readprobe-cliff-logs.png new file mode 100644 index 000000000..398926940 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-cliff-logs.png differ diff --git a/benchmarks/results-probe/chart-readprobe-cliff-metrics.png b/benchmarks/results-probe/chart-readprobe-cliff-metrics.png new file mode 100644 index 000000000..f9938e63c Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-cliff-metrics.png differ diff --git a/benchmarks/results-probe/chart-readprobe-cliff-spans.png b/benchmarks/results-probe/chart-readprobe-cliff-spans.png new file mode 100644 index 000000000..90489b30a Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-cliff-spans.png differ diff --git a/benchmarks/results-probe/chart-readprobe-headline-logs.png b/benchmarks/results-probe/chart-readprobe-headline-logs.png new file mode 100644 index 000000000..1b9698a4e Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-headline-logs.png differ diff --git a/benchmarks/results-probe/chart-readprobe-headline-metrics.png b/benchmarks/results-probe/chart-readprobe-headline-metrics.png new file mode 100644 index 000000000..b034e7ccd Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-headline-metrics.png differ diff --git a/benchmarks/results-probe/chart-readprobe-headline-spans.png b/benchmarks/results-probe/chart-readprobe-headline-spans.png new file mode 100644 index 000000000..382e7ee83 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-headline-spans.png differ diff --git a/benchmarks/results-probe/chart-readprobe-ingest-time-logs.png b/benchmarks/results-probe/chart-readprobe-ingest-time-logs.png new file mode 100644 index 000000000..339686188 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-ingest-time-logs.png differ diff --git a/benchmarks/results-probe/chart-readprobe-ingest-time-metrics.png b/benchmarks/results-probe/chart-readprobe-ingest-time-metrics.png new file mode 100644 index 000000000..bf5015be2 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-ingest-time-metrics.png differ diff --git a/benchmarks/results-probe/chart-readprobe-ingest-time-spans.png b/benchmarks/results-probe/chart-readprobe-ingest-time-spans.png new file mode 100644 index 000000000..d70262b04 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-ingest-time-spans.png differ diff --git a/benchmarks/results-probe/chart-readprobe-logs.png b/benchmarks/results-probe/chart-readprobe-logs.png new file mode 100644 index 000000000..233884278 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-logs.png differ diff --git a/benchmarks/results-probe/chart-readprobe-metrics.png b/benchmarks/results-probe/chart-readprobe-metrics.png new file mode 100644 index 000000000..652199e07 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-metrics.png differ diff --git a/benchmarks/results-probe/chart-readprobe-per-endpoint-logs.png b/benchmarks/results-probe/chart-readprobe-per-endpoint-logs.png new file mode 100644 index 000000000..aa349cf4b Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-per-endpoint-logs.png differ diff --git a/benchmarks/results-probe/chart-readprobe-per-endpoint-metrics.png b/benchmarks/results-probe/chart-readprobe-per-endpoint-metrics.png new file mode 100644 index 000000000..c014236ad Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-per-endpoint-metrics.png differ diff --git a/benchmarks/results-probe/chart-readprobe-per-endpoint-spans.png b/benchmarks/results-probe/chart-readprobe-per-endpoint-spans.png new file mode 100644 index 000000000..802b5c672 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-per-endpoint-spans.png differ diff --git a/benchmarks/results-probe/chart-readprobe-signal-mix.png b/benchmarks/results-probe/chart-readprobe-signal-mix.png new file mode 100644 index 000000000..36853091d Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-signal-mix.png differ diff --git a/benchmarks/results-probe/chart-readprobe-spans.png b/benchmarks/results-probe/chart-readprobe-spans.png new file mode 100644 index 000000000..13b1e1157 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-spans.png differ diff --git a/benchmarks/results-probe/chart-readprobe-tier-scaling-logs.png b/benchmarks/results-probe/chart-readprobe-tier-scaling-logs.png new file mode 100644 index 000000000..7f0181c96 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-tier-scaling-logs.png differ diff --git a/benchmarks/results-probe/chart-readprobe-tier-scaling-metrics.png b/benchmarks/results-probe/chart-readprobe-tier-scaling-metrics.png new file mode 100644 index 000000000..a00622b55 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-tier-scaling-metrics.png differ diff --git a/benchmarks/results-probe/chart-readprobe-tier-scaling-spans.png b/benchmarks/results-probe/chart-readprobe-tier-scaling-spans.png new file mode 100644 index 000000000..ea603aac6 Binary files /dev/null and b/benchmarks/results-probe/chart-readprobe-tier-scaling-spans.png differ diff --git a/benchmarks/results-probe/summary.md b/benchmarks/results-probe/summary.md new file mode 100644 index 000000000..82a2e39f8 --- /dev/null +++ b/benchmarks/results-probe/summary.md @@ -0,0 +1,29 @@ +# Traceway hardware benchmark — summary + +> See [../charts.md](../charts.md) for a guide to reading these charts. + +Runs analyzed: 3 + +## Read-probe scenario + +Failure: a read probe exceeded the configured threshold (default 5000ms) or returned an error. Max fill level passed is the largest row count at which the read still came back in time. + +### Spans — probing `/api/endpoints/grouped` + +| Tier | Mode | Max spans rows passed | Read latency @ max (ms) | First failing fill | Read latency @ failing (ms) | +|------|------|----------------|-------------------|--------------------|------------------------| +| ccx13 | duckdb | 10,000,000 | 636 | 101,023,744 | 6005 | + +### Metrics — probing `/api/metrics/application` + +| Tier | Mode | Max metric_points rows passed | Read latency @ max (ms) | First failing fill | Read latency @ failing (ms) | +|------|------|----------------|-------------------|--------------------|------------------------| +| ccx13 | duckdb | 100,000,000 | 2490 | — | — | + +### Logs — probing `/api/logs` + +| Tier | Mode | Max log_records rows passed | Read latency @ max (ms) | First failing fill | Read latency @ failing (ms) | +|------|------|----------------|-------------------|--------------------|------------------------| +| ccx13 | duckdb | 10,000,000 | 54 | 100,818,944 | 916 | + +Generated by `benchmarks/scripts/chart.py`. diff --git a/benchmarks/results-throughput/ccx13-duckdb-logs-throughput.json b/benchmarks/results-throughput/ccx13-duckdb-logs-throughput.json new file mode 100644 index 000000000..81c28e287 --- /dev/null +++ b/benchmarks/results-throughput/ccx13-duckdb-logs-throughput.json @@ -0,0 +1,621 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "logs", + "scenario": "throughput", + "startedAt": "2026-07-24T11:30:32Z", + "endedAt": "2026-07-24T12:08:53Z", + "phase1": { + "kind": "batch-size-ramp", + "fixedRequestRate": 5, + "steps": [ + { + "step": 1, + "batchSize": 256, + "requestRate": 5, + "attemptedItemsPerSec": 1282.1005506633032, + "actualItemsPerSec": 1282.1005506633032, + "rejected": 0, + "ingest": { + "p50": 6.026084, + "p95": 9.047784, + "p99": 22.189845, + "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": 65528049, + "memoryUsedBytes": 84482048 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 1024, + "requestRate": 5, + "attemptedItemsPerSec": 3865.1149831475036, + "actualItemsPerSec": 3865.1149831475036, + "rejected": 0, + "ingest": { + "p50": 15.996343999999999, + "p95": 25.107897, + "p99": 38.957837000000005, + "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": 52178944, + "walSizeBytes": 6101639, + "memoryUsedBytes": 67108864 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 4096, + "requestRate": 5, + "attemptedItemsPerSec": 15452.195711831737, + "actualItemsPerSec": 15452.195711831737, + "rejected": 0, + "ingest": { + "p50": 52.875378, + "p95": 74.948872, + "p99": 84.39735399999999, + "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": 211824640, + "walSizeBytes": 20900144, + "memoryUsedBytes": 244056064 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 8192, + "requestRate": 5, + "attemptedItemsPerSec": 30979.501788907815, + "actualItemsPerSec": 30979.501788907815, + "rejected": 0, + "ingest": { + "p50": 75.997334, + "p95": 120.664288, + "p99": 173.91404, + "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": 527183872, + "walSizeBytes": 52259993, + "memoryUsedBytes": 592445440 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 61644.67305682919, + "actualItemsPerSec": 61644.67305682919, + "rejected": 0, + "ingest": { + "p50": 147.833437, + "p95": 621.275719, + "p99": 764.823338, + "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": 1169174528, + "walSizeBytes": 257846844, + "memoryUsedBytes": 1497366528 + }, + "passed": true + } + ], + "maxBatchSize": 16384 + }, + "phase2": { + "kind": "request-rate-ramp", + "fixedBatchSize": 16384, + "steps": [ + { + "step": 1, + "batchSize": 16384, + "requestRate": 1, + "attemptedItemsPerSec": 16520.462138814757, + "actualItemsPerSec": 16520.462138814757, + "rejected": 0, + "ingest": { + "p50": 151.45435500000002, + "p95": 192.773638, + "p99": 230.152525, + "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": 1344811008, + "walSizeBytes": 83621807, + "memoryUsedBytes": 1450967040 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 77521.28894060008, + "actualItemsPerSec": 77521.28894060008, + "rejected": 0, + "ingest": { + "p50": 161.121305, + "p95": 686.874785, + "p99": 766.774224, + "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": 2160603136, + "walSizeBytes": 69689211, + "memoryUsedBytes": 2272319488 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 16384, + "requestRate": 10, + "attemptedItemsPerSec": 138444.81198357505, + "actualItemsPerSec": 80922.88821325115, + "rejected": 0, + "ingest": { + "p50": 5604.567692, + "p95": 6089.607695, + "p99": 6511.058937, + "ok": 619, + "errors": 440, + "errRate": 0.4154863078375826 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3037736960, + "walSizeBytes": 104532766, + "memoryUsedBytes": 3165388800 + }, + "passed": false, + "failReason": "combined error rate 41.55% (http 41.55% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 4, + "batchSize": 16384, + "requestRate": 7.5, + "attemptedItemsPerSec": 93039.78242669697, + "actualItemsPerSec": 72523.98770620339, + "rejected": 0, + "ingest": { + "p50": 5563.397334, + "p95": 5998.371059, + "p99": 6530.415977, + "ok": 555, + "errors": 157, + "errRate": 0.2205056179775281 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3811061760, + "walSizeBytes": 243903881, + "memoryUsedBytes": 3979364352 + }, + "passed": false, + "failReason": "combined error rate 22.05% (http 22.05% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 6.25, + "attemptedItemsPerSec": 79843.6788865734, + "actualItemsPerSec": 75262.48419636016, + "rejected": 0, + "ingest": { + "p50": 5155.063297, + "p95": 5772.7216769999995, + "p99": 6306.224274, + "ok": 575, + "errors": 35, + "errRate": 0.05737704918032787 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4643106816, + "walSizeBytes": 257842731, + "memoryUsedBytes": 3972530176 + }, + "passed": false, + "failReason": "combined error rate 5.74% (http 5.74% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 6, + "batchSize": 16384, + "requestRate": 5.625, + "attemptedItemsPerSec": 76111.81085870978, + "actualItemsPerSec": 76111.81085870978, + "rejected": 0, + "ingest": { + "p50": 433.886868, + "p95": 836.2944759999999, + "p99": 952.8466930000001, + "ok": 559, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5450248192, + "walSizeBytes": 188154593, + "memoryUsedBytes": 3903586304 + }, + "passed": true + } + ], + "maxRequestRate": 5.625 + }, + "phase3": { + "kind": "small-batch-rate-ramp", + "fixedBatchSize": 100, + "steps": [ + { + "step": 1, + "batchSize": 100, + "requestRate": 10, + "attemptedItemsPerSec": 1004.9603763804067, + "actualItemsPerSec": 1004.9603763804067, + "rejected": 0, + "ingest": { + "p50": 3.400628, + "p95": 4.261703000000001, + "p99": 6.152418, + "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": 5450248192, + "walSizeBytes": 253691337, + "memoryUsedBytes": 3980394496 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 100, + "requestRate": 100, + "attemptedItemsPerSec": 9752.182068055912, + "actualItemsPerSec": 9752.182068055912, + "rejected": 0, + "ingest": { + "p50": 2.845141, + "p95": 3.671995, + "p99": 7.382307, + "ok": 11703, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5554057216, + "walSizeBytes": 240302486, + "memoryUsedBytes": 3982491648 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 100, + "requestRate": 1000, + "attemptedItemsPerSec": 77234.26686100388, + "actualItemsPerSec": 77234.26686100388, + "rejected": 0, + "ingest": { + "p50": 612.093282, + "p95": 1024.209943, + "p99": 1239.1098439999998, + "ok": 93487, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 6401044480, + "walSizeBytes": 43438566, + "memoryUsedBytes": 3771504640 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 100, + "requestRate": 5000, + "attemptedItemsPerSec": 78205.12988066602, + "actualItemsPerSec": 78205.12988066602, + "rejected": 0, + "ingest": { + "p50": 610.644784, + "p95": 986.570248, + "p99": 1203.912326, + "ok": 94275, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 7192981504, + "walSizeBytes": 207921699, + "memoryUsedBytes": 3910402048 + }, + "passed": false, + "failReason": "achieved 782.05 req/sec is below 70% of target 5000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 5, + "batchSize": 100, + "requestRate": 3000, + "attemptedItemsPerSec": 77713.10811618977, + "actualItemsPerSec": 77713.10811618977, + "rejected": 0, + "ingest": { + "p50": 608.9764749999999, + "p95": 1065.576631, + "p99": 1293.378363, + "ok": 93882, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 8038133760, + "walSizeBytes": 24717970, + "memoryUsedBytes": 3745294336 + }, + "passed": false, + "failReason": "achieved 777.13 req/sec is below 70% of target 3000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 6, + "batchSize": 100, + "requestRate": 2000, + "attemptedItemsPerSec": 77945.1494285013, + "actualItemsPerSec": 77945.1494285013, + "rejected": 0, + "ingest": { + "p50": 614.335725, + "p95": 1021.243734, + "p99": 1221.0479030000001, + "ok": 93937, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 8832954368, + "walSizeBytes": 181304915, + "memoryUsedBytes": 3876079616 + }, + "passed": false, + "failReason": "achieved 779.45 req/sec is below 70% of target 2000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 7, + "batchSize": 100, + "requestRate": 1500, + "attemptedItemsPerSec": 77564.1467655176, + "actualItemsPerSec": 77564.1467655176, + "rejected": 0, + "ingest": { + "p50": 614.458254, + "p95": 1067.568106, + "p99": 1301.191288, + "ok": 93605, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 9660805120, + "walSizeBytes": 254879940, + "memoryUsedBytes": 3999796225 + }, + "passed": false, + "failReason": "achieved 775.64 req/sec is below 70% of target 1500.00 req/sec (workers saturated, SUT past cliff)" + } + ], + "maxRequestRate": 1000 + }, + "maxSustainableItemsPerSec": 77521.28894060008, + "bytesOnDisk": 9713389568, + "storedRows": 110975836, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/results-throughput/ccx13-duckdb-metrics-throughput.json b/benchmarks/results-throughput/ccx13-duckdb-metrics-throughput.json new file mode 100644 index 000000000..61d3bfa77 --- /dev/null +++ b/benchmarks/results-throughput/ccx13-duckdb-metrics-throughput.json @@ -0,0 +1,684 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "metrics", + "scenario": "throughput", + "startedAt": "2026-07-24T10:41:49Z", + "endedAt": "2026-07-24T11:24:10Z", + "phase1": { + "kind": "batch-size-ramp", + "fixedRequestRate": 5, + "steps": [ + { + "step": 1, + "batchSize": 256, + "requestRate": 5, + "attemptedItemsPerSec": 1282.1222175580785, + "actualItemsPerSec": 1282.1222175580785, + "rejected": 0, + "ingest": { + "p50": 2.799009, + "p95": 3.18526, + "p99": 4.0277769999999995, + "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": 17548411, + "memoryUsedBytes": 24084480 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 1024, + "requestRate": 5, + "attemptedItemsPerSec": 3857.0311887938183, + "actualItemsPerSec": 3857.0311887938183, + "rejected": 0, + "ingest": { + "p50": 6.143979, + "p95": 7.064983000000001, + "p99": 13.306470000000001, + "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": 12288, + "walSizeBytes": 70022561, + "memoryUsedBytes": 90931200 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 4096, + "requestRate": 5, + "attemptedItemsPerSec": 15427.009774571474, + "actualItemsPerSec": 15427.009774571474, + "rejected": 0, + "ingest": { + "p50": 15.908387999999999, + "p95": 25.948497, + "p99": 40.599333, + "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": 25440256, + "walSizeBytes": 23221008, + "memoryUsedBytes": 60293120 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 8192, + "requestRate": 5, + "attemptedItemsPerSec": 30919.53050757839, + "actualItemsPerSec": 30919.53050757839, + "rejected": 0, + "ingest": { + "p50": 27.759318, + "p95": 60.379905, + "p99": 64.37060799999999, + "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": 49557504, + "walSizeBytes": 186672326, + "memoryUsedBytes": 284950528 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 62799.16703549942, + "actualItemsPerSec": 62799.16703549942, + "rejected": 0, + "ingest": { + "p50": 52.340124, + "p95": 80.154847, + "p99": 86.631638, + "ok": 460, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 146288640, + "walSizeBytes": 7429492, + "memoryUsedBytes": 162529280 + }, + "passed": true + } + ], + "maxBatchSize": 16384 + }, + "phase2": { + "kind": "request-rate-ramp", + "fixedBatchSize": 16384, + "steps": [ + { + "step": 1, + "batchSize": 16384, + "requestRate": 1, + "attemptedItemsPerSec": 16642.917556192093, + "actualItemsPerSec": 16642.917556192093, + "rejected": 0, + "ingest": { + "p50": 52.230411999999994, + "p95": 82.730541, + "p99": 86.880504, + "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": 146288640, + "walSizeBytes": 234028754, + "memoryUsedBytes": 439091200 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 78064.28427111397, + "actualItemsPerSec": 78064.28427111397, + "rejected": 0, + "ingest": { + "p50": 52.060625, + "p95": 80.691232, + "p99": 85.72561099999999, + "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": 266612736, + "walSizeBytes": 5572121, + "memoryUsedBytes": 280494080 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 16384, + "requestRate": 10, + "attemptedItemsPerSec": 143690.23019395786, + "actualItemsPerSec": 143690.23019395786, + "rejected": 0, + "ingest": { + "p50": 44.911471, + "p95": 75.90725900000001, + "p99": 104.35861100000001, + "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": 435695616, + "walSizeBytes": 154161606, + "memoryUsedBytes": 631767040 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 16384, + "requestRate": 20, + "attemptedItemsPerSec": 287075.23751550063, + "actualItemsPerSec": 287075.23751550063, + "rejected": 0, + "ingest": { + "p50": 78.277174, + "p95": 568.027591, + "p99": 656.0039429999999, + "ok": 2104, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 797978624, + "walSizeBytes": 185735548, + "memoryUsedBytes": 1032060928 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 40, + "attemptedItemsPerSec": 562244.2313861073, + "actualItemsPerSec": 316139.6551332827, + "rejected": 0, + "ingest": { + "p50": 5187.867652, + "p95": 5325.7733339999995, + "p99": 5728.080768, + "ok": 2415, + "errors": 1880, + "errRate": 0.43771827706635624 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1210331136, + "walSizeBytes": 256313826, + "memoryUsedBytes": 1535979520 + }, + "passed": false, + "failReason": "combined error rate 43.77% (http 43.77% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 6, + "batchSize": 16384, + "requestRate": 30, + "attemptedItemsPerSec": 458664.9163715618, + "actualItemsPerSec": 346223.9451491955, + "rejected": 0, + "ingest": { + "p50": 5163.184002999999, + "p95": 5308.62522, + "p99": 5745.203487999999, + "ok": 2645, + "errors": 859, + "errRate": 0.245148401826484 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 1669345280, + "walSizeBytes": 252599019, + "memoryUsedBytes": 1988177920 + }, + "passed": false, + "failReason": "combined error rate 24.51% (http 24.51% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 7, + "batchSize": 16384, + "requestRate": 25, + "attemptedItemsPerSec": 366325.00190927065, + "actualItemsPerSec": 331144.20022644533, + "rejected": 0, + "ingest": { + "p50": 5109.071712000001, + "p95": 5272.626810000001, + "p99": 5665.372533000001, + "ok": 2532, + "errors": 269, + "errRate": 0.09603712959657265 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2129932288, + "walSizeBytes": 31574925, + "memoryUsedBytes": 2176319488 + }, + "passed": false, + "failReason": "combined error rate 9.60% (http 9.60% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 8, + "batchSize": 16384, + "requestRate": 22.5, + "attemptedItemsPerSec": 322993.5036290339, + "actualItemsPerSec": 322993.5036290339, + "rejected": 0, + "ingest": { + "p50": 2193.633558, + "p95": 4228.651153999999, + "p99": 4490.100111000001, + "ok": 2452, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2543071232, + "walSizeBytes": 167161318, + "memoryUsedBytes": 2762379264 + }, + "passed": true + } + ], + "maxRequestRate": 22.5 + }, + "phase3": { + "kind": "small-batch-rate-ramp", + "fixedBatchSize": 100, + "steps": [ + { + "step": 1, + "batchSize": 100, + "requestRate": 10, + "attemptedItemsPerSec": 1009.1356278243964, + "actualItemsPerSec": 1009.1356278243964, + "rejected": 0, + "ingest": { + "p50": 2.11458, + "p95": 3.046506, + "p99": 11.56833, + "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": 2543071232, + "walSizeBytes": 192226100, + "memoryUsedBytes": 2784485376 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 100, + "requestRate": 100, + "attemptedItemsPerSec": 9759.01417971168, + "actualItemsPerSec": 9759.01417971168, + "rejected": 0, + "ingest": { + "p50": 1.604298, + "p95": 1.990642, + "p99": 4.682382, + "ok": 11711, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2566926336, + "walSizeBytes": 69643203, + "memoryUsedBytes": 2660499456 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 100, + "requestRate": 1000, + "attemptedItemsPerSec": 99576.6617495547, + "actualItemsPerSec": 99576.6617495547, + "rejected": 0, + "ingest": { + "p50": 0.841298, + "p95": 2.8542530000000004, + "p99": 10.670081999999999, + "ok": 119493, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2688299008, + "walSizeBytes": 143740139, + "memoryUsedBytes": 2902458368 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 100, + "requestRate": 5000, + "attemptedItemsPerSec": 229731.4621205375, + "actualItemsPerSec": 229731.4621205375, + "rejected": 0, + "ingest": { + "p50": 210.738927, + "p95": 462.78889200000003, + "p99": 653.24186, + "ok": 275790, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2981113856, + "walSizeBytes": 186083781, + "memoryUsedBytes": 3307208704 + }, + "passed": false, + "failReason": "achieved 2297.31 req/sec is below 70% of target 5000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 5, + "batchSize": 100, + "requestRate": 3000, + "attemptedItemsPerSec": 224984.41471320126, + "actualItemsPerSec": 224984.41471320126, + "rejected": 0, + "ingest": { + "p50": 212.784039, + "p95": 474.648219, + "p99": 699.670686, + "ok": 270496, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3274190848, + "walSizeBytes": 158703557, + "memoryUsedBytes": 3625975808 + }, + "passed": true + }, + { + "step": 6, + "batchSize": 100, + "requestRate": 4000, + "attemptedItemsPerSec": 223781.89581116269, + "actualItemsPerSec": 223781.89581116269, + "rejected": 0, + "ingest": { + "p50": 214.013918, + "p95": 479.47198099999997, + "p99": 676.398635, + "ok": 268928, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3566481408, + "walSizeBytes": 121674027, + "memoryUsedBytes": 3837440000 + }, + "passed": false, + "failReason": "achieved 2237.82 req/sec is below 70% of target 4000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 7, + "batchSize": 100, + "requestRate": 3500, + "attemptedItemsPerSec": 220873.9907189285, + "actualItemsPerSec": 220873.9907189285, + "rejected": 0, + "ingest": { + "p50": 214.885093, + "p95": 495.238267, + "p99": 696.574892, + "ok": 265204, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3859296256, + "walSizeBytes": 37061531, + "memoryUsedBytes": 3729260544 + }, + "passed": false, + "failReason": "achieved 2208.74 req/sec is below 70% of target 3500.00 req/sec (workers saturated, SUT past cliff)" + } + ], + "maxRequestRate": 3000 + }, + "maxSustainableItemsPerSec": 322993.5036290339, + "bytesOnDisk": 3897454592, + "storedRows": 362654692, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/results-throughput/ccx13-duckdb-spans-throughput.json b/benchmarks/results-throughput/ccx13-duckdb-spans-throughput.json new file mode 100644 index 000000000..7961dbb79 --- /dev/null +++ b/benchmarks/results-throughput/ccx13-duckdb-spans-throughput.json @@ -0,0 +1,653 @@ +{ + "tier": "ccx13", + "mode": "duckdb", + "signal": "spans", + "scenario": "throughput", + "startedAt": "2026-07-24T09:55:02Z", + "endedAt": "2026-07-24T10:35:26Z", + "phase1": { + "kind": "batch-size-ramp", + "fixedRequestRate": 5, + "steps": [ + { + "step": 1, + "batchSize": 256, + "requestRate": 5, + "attemptedItemsPerSec": 1282.1004960792702, + "actualItemsPerSec": 1282.1004960792702, + "rejected": 0, + "ingest": { + "p50": 4.152551, + "p95": 4.815507, + "p99": 7.045231, + "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": 34979909, + "memoryUsedBytes": 48973824 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 1024, + "requestRate": 5, + "attemptedItemsPerSec": 3890.910751056585, + "actualItemsPerSec": 3890.910751056585, + "rejected": 0, + "ingest": { + "p50": 10.341252, + "p95": 15.189473999999999, + "p99": 24.761571999999997, + "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": 12288, + "walSizeBytes": 140745285, + "memoryUsedBytes": 185288704 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 4096, + "requestRate": 5, + "attemptedItemsPerSec": 15557.163154809663, + "actualItemsPerSec": 15557.163154809663, + "rejected": 0, + "ingest": { + "p50": 31.658137000000004, + "p95": 59.569067000000004, + "p99": 64.59054, + "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": 117190656, + "walSizeBytes": 50122626, + "memoryUsedBytes": 185860096 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 8192, + "requestRate": 5, + "attemptedItemsPerSec": 30909.50265608697, + "actualItemsPerSec": 30909.50265608697, + "rejected": 0, + "ingest": { + "p50": 60.280578, + "p95": 89.470443, + "p99": 97.665132, + "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": 291254272, + "walSizeBytes": 116942443, + "memoryUsedBytes": 444858368 + }, + "passed": true + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 61803.35451361905, + "actualItemsPerSec": 61803.35451361905, + "rejected": 0, + "ingest": { + "p50": 93.948374, + "p95": 155.893387, + "p99": 197.66644399999998, + "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": 643837952, + "walSizeBytes": 237591998, + "memoryUsedBytes": 948961280 + }, + "passed": true + } + ], + "maxBatchSize": 16384 + }, + "phase2": { + "kind": "request-rate-ramp", + "fixedBatchSize": 16384, + "steps": [ + { + "step": 1, + "batchSize": 16384, + "requestRate": 1, + "attemptedItemsPerSec": 16620.294638320505, + "actualItemsPerSec": 16620.294638320505, + "rejected": 0, + "ingest": { + "p50": 105.259274, + "p95": 129.88997799999999, + "p99": 134.91976, + "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": 761278464, + "walSizeBytes": 170772729, + "memoryUsedBytes": 983826432 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 16384, + "requestRate": 5, + "attemptedItemsPerSec": 77837.04996745415, + "actualItemsPerSec": 77837.04996745415, + "rejected": 0, + "ingest": { + "p50": 94.90488900000001, + "p95": 152.553587, + "p99": 222.003691, + "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": 1231302656, + "walSizeBytes": 211605079, + "memoryUsedBytes": 1502347264 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 16384, + "requestRate": 10, + "attemptedItemsPerSec": 143620.3269545908, + "actualItemsPerSec": 143620.3269545908, + "rejected": 0, + "ingest": { + "p50": 589.852765, + "p95": 923.728726, + "p99": 1025.5329040000001, + "ok": 1054, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 2114990080, + "walSizeBytes": 211597080, + "memoryUsedBytes": 2397761536 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 16384, + "requestRate": 20, + "attemptedItemsPerSec": 274992.2113559707, + "actualItemsPerSec": 140432.66227765757, + "rejected": 0, + "ingest": { + "p50": 5379.831106000001, + "p95": 5644.6617989999995, + "p99": 5993.780428, + "ok": 1076, + "errors": 1031, + "errRate": 0.48932130991931655 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3056349184, + "walSizeBytes": 40835661, + "memoryUsedBytes": 3113222144 + }, + "passed": false, + "failReason": "combined error rate 48.93% (http 48.93% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 5, + "batchSize": 16384, + "requestRate": 15, + "attemptedItemsPerSec": 197026.61827910235, + "actualItemsPerSec": 135749.7721432277, + "rejected": 0, + "ingest": { + "p50": 5347.444094, + "p95": 5602.899496, + "p99": 5883.934993999999, + "ok": 1039, + "errors": 469, + "errRate": 0.3110079575596817 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 3884986368, + "walSizeBytes": 256156755, + "memoryUsedBytes": 3995600385 + }, + "passed": false, + "failReason": "combined error rate 31.10% (http 31.10% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 6, + "batchSize": 16384, + "requestRate": 12.5, + "attemptedItemsPerSec": 158841.68669689598, + "actualItemsPerSec": 130972.42865205342, + "rejected": 0, + "ingest": { + "p50": 5307.7707390000005, + "p95": 5588.326454999999, + "p99": 5857.754388, + "ok": 1001, + "errors": 213, + "errRate": 0.17545304777594728 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 4762382336, + "walSizeBytes": 66822257, + "memoryUsedBytes": 3764549632 + }, + "passed": false, + "failReason": "combined error rate 17.55% (http 17.55% + rejected 0.00%) > 5.00% threshold" + }, + { + "step": 7, + "batchSize": 16384, + "requestRate": 11.25, + "attemptedItemsPerSec": 145361.97447005348, + "actualItemsPerSec": 132932.28268368528, + "rejected": 0, + "ingest": { + "p50": 5225.422501999999, + "p95": 5546.112275, + "p99": 5820.547549999999, + "ok": 1016, + "errors": 95, + "errRate": 0.0855085508550855 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5588398080, + "walSizeBytes": 193040313, + "memoryUsedBytes": 3913547776 + }, + "passed": false, + "failReason": "combined error rate 8.55% (http 8.55% + rejected 0.00%) > 5.00% threshold" + } + ], + "maxRequestRate": 10 + }, + "phase3": { + "kind": "small-batch-rate-ramp", + "fixedBatchSize": 100, + "steps": [ + { + "step": 1, + "batchSize": 100, + "requestRate": 10, + "attemptedItemsPerSec": 1009.1288230071176, + "actualItemsPerSec": 1009.1288230071176, + "rejected": 0, + "ingest": { + "p50": 2.70479, + "p95": 3.729988, + "p99": 5.530241, + "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": 5588398080, + "walSizeBytes": 235638809, + "memoryUsedBytes": 3968598016 + }, + "passed": true + }, + { + "step": 2, + "batchSize": 100, + "requestRate": 100, + "attemptedItemsPerSec": 9752.30446865221, + "actualItemsPerSec": 9752.30446865221, + "rejected": 0, + "ingest": { + "p50": 2.1583710000000003, + "p95": 2.821741, + "p99": 5.260931, + "ok": 11703, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 5645807616, + "walSizeBytes": 245868426, + "memoryUsedBytes": 3984326656 + }, + "passed": true + }, + { + "step": 3, + "batchSize": 100, + "requestRate": 1000, + "attemptedItemsPerSec": 99578.47755544432, + "actualItemsPerSec": 99578.47755544432, + "rejected": 0, + "ingest": { + "p50": 1.778715, + "p95": 142.550764, + "p99": 284.43098100000003, + "ok": 119496, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 6282555392, + "walSizeBytes": 133774406, + "memoryUsedBytes": 3846701056 + }, + "passed": true + }, + { + "step": 4, + "batchSize": 100, + "requestRate": 5000, + "attemptedItemsPerSec": 130139.35789710082, + "actualItemsPerSec": 130139.35789710082, + "rejected": 0, + "ingest": { + "p50": 370.786635, + "p95": 623.323806, + "p99": 778.2651269999999, + "ok": 156560, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 7094153216, + "walSizeBytes": 78926074, + "memoryUsedBytes": 3793477632 + }, + "passed": false, + "failReason": "achieved 1301.39 req/sec is below 70% of target 5000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 5, + "batchSize": 100, + "requestRate": 3000, + "attemptedItemsPerSec": 130008.67946431633, + "actualItemsPerSec": 130008.67946431633, + "rejected": 0, + "ingest": { + "p50": 368.326323, + "p95": 652.724945, + "p99": 840.6580839999999, + "ok": 156883, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 7906537472, + "walSizeBytes": 24895488, + "memoryUsedBytes": 3702788096 + }, + "passed": false, + "failReason": "achieved 1300.09 req/sec is below 70% of target 3000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 6, + "batchSize": 100, + "requestRate": 2000, + "attemptedItemsPerSec": 131149.7731845305, + "actualItemsPerSec": 131149.7731845305, + "rejected": 0, + "ingest": { + "p50": 366.194007, + "p95": 641.064808, + "p99": 807.632701, + "ok": 157805, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 8665706496, + "walSizeBytes": 255474634, + "memoryUsedBytes": 3991142400 + }, + "passed": false, + "failReason": "achieved 1311.50 req/sec is below 70% of target 2000.00 req/sec (workers saturated, SUT past cliff)" + }, + { + "step": 7, + "batchSize": 100, + "requestRate": 1500, + "attemptedItemsPerSec": 129747.72699057433, + "actualItemsPerSec": 129747.72699057433, + "rejected": 0, + "ingest": { + "p50": 371.09817699999996, + "p95": 641.704326, + "p99": 817.970244, + "ok": 156135, + "errors": 0, + "errRate": 0 + }, + "ch": { + "reachable": false, + "uptimeSec": 0, + "partsCount": 0, + "activeMerges": 0, + "longestMergeSec": 0 + }, + "sutIngest": { + "reachable": true, + "droppedRowsTotal": 0, + "insertFailures": 0, + "dbSizeBytes": 9473110016, + "walSizeBytes": 198744925, + "memoryUsedBytes": 3930587136 + }, + "passed": true + } + ], + "maxRequestRate": 1500 + }, + "maxSustainableItemsPerSec": 143620.3269545908, + "bytesOnDisk": 9675419648, + "storedRows": 185922340, + "sutContainer": { + "status": "running", + "oomKilled": false, + "exitCode": 0, + "restartCount": 0 + } +} diff --git a/benchmarks/results-throughput/ccx13-sqlite-metrics-throughput.json b/benchmarks/results-throughput/ccx13-sqlite-metrics-throughput.json deleted file mode 100644 index 191bc879a..000000000 --- a/benchmarks/results-throughput/ccx13-sqlite-metrics-throughput.json +++ /dev/null @@ -1,298 +0,0 @@ -{ - "tier": "ccx13", - "mode": "sqlite", - "signal": "metrics", - "scenario": "throughput", - "startedAt": "2026-05-23T04:58:05Z", - "endedAt": "2026-05-23T05:22:42Z", - "phase1": { - "kind": "batch-size-ramp", - "fixedRequestRate": 5, - "steps": [ - { - "step": 1, - "batchSize": 256, - "requestRate": 5, - "attemptedItemsPerSec": 1282.004034006758, - "actualItemsPerSec": 1282.004034006758, - "rejected": 0, - "ingest": { - "p50": 14.182811, - "p95": 15.942796, - "p99": 18.356655999999997, - "ok": 601, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": true - }, - { - "step": 2, - "batchSize": 1024, - "requestRate": 5, - "attemptedItemsPerSec": 3898.4833029201486, - "actualItemsPerSec": 3898.4833029201486, - "rejected": 0, - "ingest": { - "p50": 46.60554, - "p95": 49.190736, - "p99": 53.169051, - "ok": 457, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": true - }, - { - "step": 3, - "batchSize": 4096, - "requestRate": 5, - "attemptedItemsPerSec": 15547.156034271607, - "actualItemsPerSec": 15547.156034271607, - "rejected": 0, - "ingest": { - "p50": 176.412991, - "p95": 186.146252, - "p99": 191.044352, - "ok": 456, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": true - }, - { - "step": 4, - "batchSize": 8192, - "requestRate": 5, - "attemptedItemsPerSec": 24758.511378158793, - "actualItemsPerSec": 1147.7455605768978, - "rejected": 0, - "ingest": { - "p50": 12640.689540000001, - "p95": 24442.002215, - "p99": 24442.002215, - "ok": 21, - "errors": 432, - "errRate": 0.9536423841059603 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": false, - "failReason": "combined error rate 95.36% (http 95.36% + rejected 0.00%) \u003e 5.00% threshold" - } - ], - "maxBatchSize": 4096 - }, - "phase2": { - "kind": "request-rate-ramp", - "fixedBatchSize": 4096, - "steps": [ - { - "step": 1, - "batchSize": 4096, - "requestRate": 1, - "attemptedItemsPerSec": 4157.7885270983625, - "actualItemsPerSec": 3203.5419798954595, - "rejected": 0, - "ingest": { - "p50": 180.989608, - "p95": 25037.939551, - "p99": 28441.417234, - "ok": 94, - "errors": 28, - "errRate": 0.22950819672131148 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": false, - "failReason": "combined error rate 22.95% (http 22.95% + rejected 0.00%) \u003e 5.00% threshold" - } - ] - }, - "phase3": { - "kind": "small-batch-rate-ramp", - "fixedBatchSize": 100, - "steps": [ - { - "step": 1, - "batchSize": 100, - "requestRate": 10, - "attemptedItemsPerSec": 1001.6145903619727, - "actualItemsPerSec": 1001.6145903619727, - "rejected": 0, - "ingest": { - "p50": 5.385344, - "p95": 10.277681000000001, - "p99": 11.558016, - "ok": 1202, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": true - }, - { - "step": 2, - "batchSize": 100, - "requestRate": 100, - "attemptedItemsPerSec": 9751.726877729683, - "actualItemsPerSec": 9751.726877729683, - "rejected": 0, - "ingest": { - "p50": 4.790314, - "p95": 10.325179, - "p99": 14.537877, - "ok": 11703, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": true - }, - { - "step": 3, - "batchSize": 100, - "requestRate": 1000, - "attemptedItemsPerSec": 16453.96628575246, - "actualItemsPerSec": 16453.96628575246, - "rejected": 0, - "ingest": { - "p50": 3074.265864, - "p95": 3629.118197, - "p99": 3856.044782, - "ok": 20005, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": false, - "failReason": "achieved 164.54 req/sec is below 70% of target 1000.00 req/sec (workers saturated, SUT past cliff)" - }, - { - "step": 4, - "batchSize": 100, - "requestRate": 550, - "attemptedItemsPerSec": 16541.70049989337, - "actualItemsPerSec": 16541.70049989337, - "rejected": 0, - "ingest": { - "p50": 3077.627502, - "p95": 3631.414504, - "p99": 3886.4199360000002, - "ok": 20106, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": false, - "failReason": "achieved 165.42 req/sec is below 70% of target 550.00 req/sec (workers saturated, SUT past cliff)" - }, - { - "step": 5, - "batchSize": 100, - "requestRate": 325, - "attemptedItemsPerSec": 16414.805205046458, - "actualItemsPerSec": 16414.805205046458, - "rejected": 0, - "ingest": { - "p50": 3096.894328, - "p95": 3656.6241760000003, - "p99": 3898.193317, - "ok": 19965, - "errors": 0, - "errRate": 0 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": false, - "failReason": "achieved 164.15 req/sec is below 70% of target 325.00 req/sec (workers saturated, SUT past cliff)" - }, - { - "step": 6, - "batchSize": 100, - "requestRate": 212.5, - "attemptedItemsPerSec": 16828.717117277138, - "actualItemsPerSec": 16586.086182836163, - "rejected": 0, - "ingest": { - "p50": 3037.308098, - "p95": 3575.279847, - "p99": 3821.396914, - "ok": 20166, - "errors": 295, - "errRate": 0.014417672645520747 - }, - "ch": { - "reachable": false, - "uptimeSec": 0, - "partsCount": 0, - "activeMerges": 0, - "longestMergeSec": 0 - }, - "passed": true - } - ], - "maxRequestRate": 212.5 - }, - "maxSustainableItemsPerSec": 16586.086182836163 -} diff --git a/benchmarks/results-throughput/chart-batch-efficiency-logs.png b/benchmarks/results-throughput/chart-batch-efficiency-logs.png new file mode 100644 index 000000000..f2f507431 Binary files /dev/null and b/benchmarks/results-throughput/chart-batch-efficiency-logs.png differ diff --git a/benchmarks/results-throughput/chart-batch-efficiency-metrics.png b/benchmarks/results-throughput/chart-batch-efficiency-metrics.png index 6d7eff612..37e9f4799 100644 Binary files a/benchmarks/results-throughput/chart-batch-efficiency-metrics.png and b/benchmarks/results-throughput/chart-batch-efficiency-metrics.png differ diff --git a/benchmarks/results-throughput/chart-batch-efficiency-spans.png b/benchmarks/results-throughput/chart-batch-efficiency-spans.png new file mode 100644 index 000000000..00e1342ea Binary files /dev/null and b/benchmarks/results-throughput/chart-batch-efficiency-spans.png differ diff --git a/benchmarks/results-throughput/chart-cliff-logs.png b/benchmarks/results-throughput/chart-cliff-logs.png new file mode 100644 index 000000000..73e80371f Binary files /dev/null and b/benchmarks/results-throughput/chart-cliff-logs.png differ diff --git a/benchmarks/results-throughput/chart-cliff-metrics.png b/benchmarks/results-throughput/chart-cliff-metrics.png index c8ed1f9e8..25168a494 100644 Binary files a/benchmarks/results-throughput/chart-cliff-metrics.png and b/benchmarks/results-throughput/chart-cliff-metrics.png differ diff --git a/benchmarks/results-throughput/chart-cliff-spans.png b/benchmarks/results-throughput/chart-cliff-spans.png new file mode 100644 index 000000000..26cf5f7a9 Binary files /dev/null and b/benchmarks/results-throughput/chart-cliff-spans.png differ diff --git a/benchmarks/results-throughput/chart-logs.png b/benchmarks/results-throughput/chart-logs.png new file mode 100644 index 000000000..c6b998b03 Binary files /dev/null and b/benchmarks/results-throughput/chart-logs.png differ diff --git a/benchmarks/results-throughput/chart-metrics.png b/benchmarks/results-throughput/chart-metrics.png index e7213acd6..3732d3313 100644 Binary files a/benchmarks/results-throughput/chart-metrics.png and b/benchmarks/results-throughput/chart-metrics.png differ diff --git a/benchmarks/results-throughput/chart-pareto-logs.png b/benchmarks/results-throughput/chart-pareto-logs.png new file mode 100644 index 000000000..712d30f8f Binary files /dev/null and b/benchmarks/results-throughput/chart-pareto-logs.png differ diff --git a/benchmarks/results-throughput/chart-pareto-metrics.png b/benchmarks/results-throughput/chart-pareto-metrics.png index 5ded534a7..45d69a6f8 100644 Binary files a/benchmarks/results-throughput/chart-pareto-metrics.png and b/benchmarks/results-throughput/chart-pareto-metrics.png differ diff --git a/benchmarks/results-throughput/chart-pareto-spans.png b/benchmarks/results-throughput/chart-pareto-spans.png new file mode 100644 index 000000000..075e0835a Binary files /dev/null and b/benchmarks/results-throughput/chart-pareto-spans.png differ diff --git a/benchmarks/results-throughput/chart-phase1-batch-logs.png b/benchmarks/results-throughput/chart-phase1-batch-logs.png new file mode 100644 index 000000000..fc3625a88 Binary files /dev/null and b/benchmarks/results-throughput/chart-phase1-batch-logs.png differ diff --git a/benchmarks/results-throughput/chart-phase1-batch-metrics.png b/benchmarks/results-throughput/chart-phase1-batch-metrics.png index f6e2ccb4c..c44fdd912 100644 Binary files a/benchmarks/results-throughput/chart-phase1-batch-metrics.png and b/benchmarks/results-throughput/chart-phase1-batch-metrics.png differ diff --git a/benchmarks/results-throughput/chart-phase1-batch-spans.png b/benchmarks/results-throughput/chart-phase1-batch-spans.png new file mode 100644 index 000000000..ae0ca9f67 Binary files /dev/null and b/benchmarks/results-throughput/chart-phase1-batch-spans.png differ diff --git a/benchmarks/results-throughput/chart-phase2-rate-logs.png b/benchmarks/results-throughput/chart-phase2-rate-logs.png new file mode 100644 index 000000000..386e997bb Binary files /dev/null and b/benchmarks/results-throughput/chart-phase2-rate-logs.png differ diff --git a/benchmarks/results-throughput/chart-phase2-rate-metrics.png b/benchmarks/results-throughput/chart-phase2-rate-metrics.png index 4dccd184e..1c5a496db 100644 Binary files a/benchmarks/results-throughput/chart-phase2-rate-metrics.png and b/benchmarks/results-throughput/chart-phase2-rate-metrics.png differ diff --git a/benchmarks/results-throughput/chart-phase2-rate-spans.png b/benchmarks/results-throughput/chart-phase2-rate-spans.png new file mode 100644 index 000000000..d7cc5cba5 Binary files /dev/null and b/benchmarks/results-throughput/chart-phase2-rate-spans.png differ diff --git a/benchmarks/results-throughput/chart-phase3-rate-logs.png b/benchmarks/results-throughput/chart-phase3-rate-logs.png new file mode 100644 index 000000000..82f826502 Binary files /dev/null and b/benchmarks/results-throughput/chart-phase3-rate-logs.png differ diff --git a/benchmarks/results-throughput/chart-phase3-rate-metrics.png b/benchmarks/results-throughput/chart-phase3-rate-metrics.png index 6f8031900..bfb922089 100644 Binary files a/benchmarks/results-throughput/chart-phase3-rate-metrics.png and b/benchmarks/results-throughput/chart-phase3-rate-metrics.png differ diff --git a/benchmarks/results-throughput/chart-phase3-rate-spans.png b/benchmarks/results-throughput/chart-phase3-rate-spans.png new file mode 100644 index 000000000..9492fd6a3 Binary files /dev/null and b/benchmarks/results-throughput/chart-phase3-rate-spans.png differ diff --git a/benchmarks/results-throughput/chart-signal-mix.png b/benchmarks/results-throughput/chart-signal-mix.png index 2e8c6c787..b49e56579 100644 Binary files a/benchmarks/results-throughput/chart-signal-mix.png and b/benchmarks/results-throughput/chart-signal-mix.png differ diff --git a/benchmarks/results-throughput/chart-spans.png b/benchmarks/results-throughput/chart-spans.png new file mode 100644 index 000000000..cfa4f268a Binary files /dev/null and b/benchmarks/results-throughput/chart-spans.png differ diff --git a/benchmarks/results-throughput/chart-tier-scaling-logs.png b/benchmarks/results-throughput/chart-tier-scaling-logs.png new file mode 100644 index 000000000..b8dfde40a Binary files /dev/null and b/benchmarks/results-throughput/chart-tier-scaling-logs.png differ diff --git a/benchmarks/results-throughput/chart-tier-scaling-metrics.png b/benchmarks/results-throughput/chart-tier-scaling-metrics.png index 8b85e0ee8..6e8a9281e 100644 Binary files a/benchmarks/results-throughput/chart-tier-scaling-metrics.png and b/benchmarks/results-throughput/chart-tier-scaling-metrics.png differ diff --git a/benchmarks/results-throughput/chart-tier-scaling-spans.png b/benchmarks/results-throughput/chart-tier-scaling-spans.png new file mode 100644 index 000000000..b237be11f Binary files /dev/null and b/benchmarks/results-throughput/chart-tier-scaling-spans.png differ diff --git a/benchmarks/results-throughput/summary.md b/benchmarks/results-throughput/summary.md index 9582a6438..f16dd1131 100644 --- a/benchmarks/results-throughput/summary.md +++ b/benchmarks/results-throughput/summary.md @@ -2,16 +2,28 @@ > See [../charts.md](../charts.md) for a guide to reading these charts. -Runs analyzed: 1 +Runs analyzed: 3 ## Throughput scenario Failure threshold: combined HTTP error rate + OTLP rejected items > 5% of attempted. +### Spans + +| Tier | Mode | Max spans/sec | P1 max batch | P2 max req/sec @ batch | P3 max req/sec @ batch=100 | +|------|------|---------|--------------|-------------------------|-------------------------------| +| ccx13 | duckdb | 143,620 | 16,384 | 10 @ 16,384 | 1500 | + ### Metrics | Tier | Mode | Max data points/sec | P1 max batch | P2 max req/sec @ batch | P3 max req/sec @ batch=100 | |------|------|---------|--------------|-------------------------|-------------------------------| -| ccx13 | sqlite | 16,586 | 4,096 | — | 212.5 | +| ccx13 | duckdb | 322,993 | 16,384 | 22.5 @ 16,384 | 3000 | + +### Logs + +| Tier | Mode | Max log records/sec | P1 max batch | P2 max req/sec @ batch | P3 max req/sec @ batch=100 | +|------|------|---------|--------------|-------------------------|-------------------------------| +| ccx13 | duckdb | 77,521 | 16,384 | 5.625 @ 16,384 | 1000 | Generated by `benchmarks/scripts/chart.py`. diff --git a/docker-compose.duckdb.yml b/docker-compose.duckdb.yml index 258b79850..be2615ad0 100644 --- a/docker-compose.duckdb.yml +++ b/docker-compose.duckdb.yml @@ -14,10 +14,21 @@ services: # container's RAM or the backend gets OOM-killed under ingest. DUCKDB_MEMORY_LIMIT: "2GB" # DUCKDB_THREADS: "4" - # Raise under sustained ingest to reduce WAL checkpoint stalls; costs a - # larger WAL and longer restart replay. DuckDB default is 16MB. + # WAL checkpoint threshold. The backend defaults to 256MB (DuckDB's own + # 16MB default stalls sustained ingest); lower it if restart replay time + # matters more than ingest throughput. # DUCKDB_CHECKPOINT_THRESHOLD: "256MB" + # Background write batcher for the hot telemetry tables. Defaults: + # queue 131072 rows per table, flush at 32768 rows or 100ms. A 200 on + # ingest means "accepted into the bounded queue"; a full queue answers + # 503 + Retry-After and the SDK retries. + # DUCKDB_WRITE_QUEUE_ROWS: "131072" + # DUCKDB_WRITE_FLUSH_ROWS: "32768" + # DUCKDB_WRITE_FLUSH_INTERVAL_MS: "100" + # DUCKDB_WRITE_WRITERS: "4" + # DUCKDB_WRITE_QUEUE_WAIT_MS: "2000" + # Optional retention knobs. Defaults are 30 days; set to "0" to disable. # SQLITE_RETENTION_DAYS prunes telemetry rows (DuckDB telemetry included); # SESSION_RECORDING_RETENTION_DAYS cleans on-disk recordings under