Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,9 +8,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
## [Unreleased]

### Fixed
- A bare `WHERE col = <constant>` on `spans` returns the matching rows again instead of silently returning none. `duration_ms` was a VIRTUAL generated column declared mid-table: it took a logical slot but no storage slot, so every column after it had a logical index one ahead of its physical index, and an equality on such a column probed an unrelated ART index and found nothing — a wrong result, not an error. Schema version 10 drops the column and computes the duration at the four queries that read it, so logical and physical indexes line up and the trap is gone rather than worked around; the engine-fragile `COALESCE(tool_name, '') = 'Bash'` workaround (DuckDB 1.4+ pushes `COALESCE` down too) goes with it. Verified against a copy of production (108 MB, 34 706 spans): `tool_name = 'Bash'` counted 0 rows before the migration and 6 440 after, `service_name = 'claude-code'` 0 before and 34 705 after, with the span count unchanged ([ADR-0013](docs/decisions/0013-spans-has-no-derived-columns.md))
- A failing `GET /api/v1/bash-commands` no longer renders as the "no command detail in this data" explainer. The Bash section branched on row count alone, so a request that errored looked identical to one that legitimately returned nothing, blaming Claude Code's telemetry for what was actually a server fault. Fetch failures now show the error

### Changed
- Schema version 10 removes `spans.duration_ms`. The migration moves no row data: it drops the four secondary indexes, drops the column (DuckDB refuses to `ALTER` a table an index depends on), and the existing `CREATE INDEX IF NOT EXISTS` block rebuilds them. On the 108 MB production copy the whole upgrade added 0.4 s to a cold start already dominated by WAL replay (9.5 s → 9.8 s), and a later re-apply of `schema.sql` costs 138 ms. No downgrade path: an older binary still starts against a v10 database (`CREATE TABLE IF NOT EXISTS` cannot bring the column back) but every query naming `duration_ms` then errors, so a rollback needs the pre-upgrade database too. Exported CSVs are unaffected — the `duration_ms` column of `spans.csv` was already derived in Go, so the format version does not move
- Tools page is flat: the tools table sits directly on the page instead of inside an "All Tools" card. `DataTable` already draws its own bordered surface, so the card put a box inside a box for a heading the page title already gave. Matches the Users page
- The Bash commands section no longer vanishes when it has no rows — it always renders and says why it is empty. Claude Code's tool spans carry `tool_name`, `tool_use_id` and `duration_ms` only: which tool ran, not what it ran. No `command` attribute is ever sent (verified against a captured live session, including the enhanced-telemetry beta), so this breakdown stays empty against Claude Code telemetry no matter what — the DuckDB filter-pushdown fix in 0.3.0 was a real bug fix but could not, on its own, put rows in this table. The endpoint is kept for OTLP producers that do send `command`

Expand Down
48 changes: 28 additions & 20 deletions docs/decisions/0001-storage.md
Original file line number Diff line number Diff line change
Expand Up @@ -54,33 +54,41 @@ Reasons:

## Known engine trap: virtual generated columns and secondary indexes

`spans` declares `duration_ms` as a VIRTUAL generated column and carries four
secondary indexes. That combination makes DuckDB answer some constant-equality
predicates — `WHERE tool_name = 'Bash'` — with **zero rows** instead of the
matching ones: a silent wrong result, not an error and not a slowdown.
A table that mixes a VIRTUAL generated column with secondary indexes makes
DuckDB answer some constant-equality predicates — `WHERE tool_name = 'Bash'` —
with **zero rows** instead of the matching ones: a silent wrong result, not an
error and not a slowdown.

A virtual generated column takes a logical slot but no storage slot, so every
column declared after it has logical index = physical index + 1. A column is
answered wrongly exactly when its logical index collides with the *physical*
index of an indexed column: the scan concludes an index covers the predicate,
probes that unrelated ART index for the constant, and finds nothing. On the
current layout `service_name` (logical 7) collides with `session_id` (physical
7), and `tool_name` (logical 10) with `user_id` (physical 10).
probes that unrelated ART index for the constant, and finds nothing.

Two consequences for anyone touching this schema:
`spans` used to declare `duration_ms` this way, which put `service_name`
(logical 7) on `session_id` (physical 7) and `tool_name` (logical 10) on
`user_id` (physical 10) — that is how `/api/v1/bash-commands` shipped
permanently empty. Schema version 10 drops the column and computes the duration
where it is read, so logical == physical everywhere and bare equality is correct
again. ADR-0013 records that decision and the rule it establishes: `spans`
carries no derived columns.

- **The affected set is a property of the layout, not of those two columns.**
Adding, reordering, or indexing a column silently moves the collisions.
What remains for anyone touching this schema:

- **The affected set is a property of the layout, not of any one column.**
Adding, reordering, or indexing a column moves the collisions.
`TestSpansEqualityUnderFilterPushdown` in `internal/storage` derives the set
from the live schema on every run and fails in both directions, so a moved
collision is a red build rather than an empty dashboard panel.
- **Wrapping the column keeps the predicate out of the pushdown**
(`COALESCE(col, '') = …`), which is the workaround in use today. It is not
durable: DuckDB 1.4+ pushes `COALESCE` down too, so the same guard test also
asserts the workaround still returns the truth.
from the live schema on every run and fails in both directions, so a
reintroduced hole is a red build rather than an empty dashboard panel.
- **`COALESCE(col, '') = …` keeps a predicate out of the pushdown**, which is
the escape hatch if one is ever needed again. It is not durable: DuckDB 1.4+
pushes `COALESCE` down too, so the same guard test also asserts it still
returns the truth.
- **DuckDB refuses to `ALTER` a table an index depends on**, so a spans column
change means dropping the four secondary indexes first and letting the
`CREATE INDEX IF NOT EXISTS` block recreate them. Measured at 138 ms on a
108 MB production copy (34 706 spans).

Verified present on DuckDB 1.1.3 (bundled), 1.4.1 and 1.5.5, so upgrading the
engine does not resolve it. Neither does `STORED` — DuckDB rejects stored
generated columns outright. The root-cause fix is to stop declaring
`duration_ms` as a generated column mid-table; that is a schema migration and
is tracked separately.
engine does not resolve it, and `STORED` is rejected outright. Avoiding
generated columns on indexed tables is the only durable fix.
18 changes: 4 additions & 14 deletions internal/api/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -601,7 +601,7 @@ func (h *Handler) handleSession(w http.ResponseWriter, _ *http.Request, sessionI
rows, _ := h.db.Query(`
SELECT
start_time,
duration_ms,
CAST(epoch_ms(end_time) - epoch_ms(start_time) AS DOUBLE) AS duration_ms,
name,
COALESCE(tool_name, ''),
COALESCE(model, ''),
Expand Down Expand Up @@ -805,7 +805,7 @@ parts AS (
SELECT
tool_name AS name,
COUNT(*) AS calls,
SUM(duration_ms) AS dur_sum,
SUM(CAST(epoch_ms(end_time) - epoch_ms(start_time) AS DOUBLE)) AS dur_sum,
COUNT(*) AS dur_calls,
COUNT(*) FILTER (WHERE status_code = 2) AS fails,
COUNT(*) AS fail_calls
Expand Down Expand Up @@ -987,16 +987,6 @@ var bashSortExprs = map[string]string{
// handleBashCommands returns per-command breakdown for Bash tool spans.
// The command is extracted from the span attributes JSON: direct "command" key first,
// then falling back to the "command" field inside a JSON-encoded "tool_input" value.
//
// The tool filter is written as COALESCE(tool_name, '') = 'Bash' rather than the
// plain equality: a bare `spans.tool_name = <const>` is pushed into the scan as a
// table filter and then matches nothing, so the plain form silently answers with
// an empty breakdown. Wrapping the column keeps the predicate out of the pushdown.
//
// Which columns this hits is a property of the spans layout rather than of
// tool_name — see the trap described in ADR-0001, and the guard test
// TestSpansEqualityUnderFilterPushdown, which fails both when the affected set
// moves and when this workaround stops being enough.
func (h *Handler) handleBashCommands(w http.ResponseWriter, r *http.Request) {
rangeKey, since := parseRange(r)
sort, order := parseSortOrder(r, bashSortExprs, "calls")
Expand Down Expand Up @@ -1030,10 +1020,10 @@ WITH cmd AS (
attributes->>'command',
TRY_CAST(attributes->>'tool_input' AS JSON)->>'command'
) AS command,
duration_ms,
CAST(epoch_ms(end_time) - epoch_ms(start_time) AS DOUBLE) AS duration_ms,
status_code
FROM spans
WHERE COALESCE(tool_name, '') = 'Bash'` + uidClause + sinceClause + `
WHERE tool_name = 'Bash'` + uidClause + sinceClause + `
),
cmd_stats AS (
SELECT
Expand Down
5 changes: 4 additions & 1 deletion internal/api/handler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -355,7 +355,10 @@ func TestSessionDetail(t *testing.T) {
}
spans, ok := body["spans"].([]any)
if !ok || len(spans) == 0 {
t.Error("expected non-empty spans")
t.Fatal("expected non-empty spans")
}
if got := spans[0].(map[string]any)["duration_ms"].(float64); got != 1000 {
t.Errorf("duration_ms: want 1000 for a 1s span, got %v", got)
}
},
},
Expand Down
119 changes: 102 additions & 17 deletions internal/storage/pushdown_test.go
Original file line number Diff line number Diff line change
@@ -1,29 +1,27 @@
package storage

import (
"database/sql"
"fmt"
"path/filepath"
"testing"
"time"
)

// pushdownBrokenSpanCols are the VARCHAR columns of spans for which the bundled
// DuckDB engine answers a bare `col = <constant>` with zero rows.
// DuckDB engine answers a bare `col = <constant>` with zero rows. Empty since
// spans stopped carrying a generated column (ADR-0013).
//
// The trigger is the table shape, not the column: `duration_ms` is a VIRTUAL
// generated column, so it takes a logical slot but no storage slot and every
// column after it has logical index = physical index + 1. A column is answered
// wrongly exactly when its logical index collides with the physical index of an
// indexed column - the scan then probes that unrelated ART index for the
// constant and finds nothing. Today service_name (logical 7) collides with
// session_id (physical 7) and tool_name (logical 10) with user_id (physical 10).
// The trigger is the table shape, not the column: a VIRTUAL generated column
// takes a logical slot but no storage slot, so every column after it has logical
// index = physical index + 1. A column is answered wrongly exactly when its
// logical index collides with the physical index of an indexed column - the scan
// then probes that unrelated ART index for the constant and finds nothing.
//
// Adding, reordering or indexing a column moves the collisions, which is why
// the test below derives the set from the live schema rather than trusting this
// list to stay complete.
var pushdownBrokenSpanCols = map[string]bool{
"service_name": true,
"tool_name": true,
}
var pushdownBrokenSpanCols = map[string]bool{}

// spansVarcharCols reads the VARCHAR columns of spans in declaration order.
func spansVarcharCols(t *testing.T, r *ReadDB) []string {
Expand Down Expand Up @@ -134,9 +132,10 @@ func truthCounts(t *testing.T, r *ReadDB, cols []string) (map[string]string, map
// pushed into the scan and then match nothing, turning a silently empty answer
// into something no reviewer can spot by reading the SQL.
//
// It fails in both directions on purpose. A column that starts disagreeing is a
// new place that needs the COALESCE guard; a column in pushdownBrokenSpanCols
// that starts agreeing means the engine was fixed and the workarounds can go.
// It fails in both directions on purpose. A column that starts disagreeing means
// the layout grew a hole again - look for a generated column before reaching for
// a COALESCE workaround; a column in pushdownBrokenSpanCols that starts agreeing
// means the trap is gone and its entry can go.
func TestSpansEqualityUnderFilterPushdown(t *testing.T) {
db, err := Open(":memory:")
if err != nil {
Expand All @@ -162,7 +161,7 @@ func TestSpansEqualityUnderFilterPushdown(t *testing.T) {
bare := count(q+" = ?", probe[c])

if got := count("COALESCE("+q+", '') = ?", probe[c]); got != want[c] {
t.Errorf("COALESCE(%s, '') = %q returned %d rows, want %d: the workaround this codebase relies on no longer returns the truth on %s",
t.Errorf("COALESCE(%s, '') = %q returned %d rows, want %d: the fallback workaround no longer returns the truth on %s",
c, probe[c], got, want[c], duckDBVersion(t, ro))
}

Expand All @@ -171,7 +170,7 @@ func TestSpansEqualityUnderFilterPushdown(t *testing.T) {
t.Errorf("%s = %q now returns the correct %d rows on %s: drop %q from pushdownBrokenSpanCols and remove its COALESCE workaround",
c, probe[c], want[c], duckDBVersion(t, ro), c)
case !broken && bare != want[c]:
t.Errorf("%s = %q returned %d rows, want %d on %s: this column is now silently dropped by filter pushdown and needs the COALESCE workaround",
t.Errorf("%s = %q returned %d rows, want %d on %s: this column is now silently dropped by filter pushdown - check whether spans grew a generated column",
c, probe[c], bare, want[c], duckDBVersion(t, ro))
}
}
Expand All @@ -191,6 +190,92 @@ func TestSpansEqualityUnderFilterPushdown(t *testing.T) {
}
}

// TestUpgradeDropsGeneratedDurationColumn covers the upgrade path the fresh-database
// test cannot: a populated v9 database still carries duration_ms as a generated
// column, and the migration has to remove it without touching the rows around it.
func TestUpgradeDropsGeneratedDurationColumn(t *testing.T) {
path := filepath.Join(t.TempDir(), "v9.duckdb")

raw, err := sql.Open("duckdb", path)
if err != nil {
t.Fatalf("raw open: %v", err)
}
if _, err := raw.Exec(`CREATE TABLE spans (
trace_id VARCHAR NOT NULL, span_id VARCHAR NOT NULL PRIMARY KEY,
parent_span_id VARCHAR, name VARCHAR NOT NULL,
start_time TIMESTAMPTZ NOT NULL, end_time TIMESTAMPTZ NOT NULL,
duration_ms DOUBLE GENERATED ALWAYS AS (epoch_ms(end_time) - epoch_ms(start_time)),
service_name VARCHAR, session_id VARCHAR, model VARCHAR, tool_name VARCHAR,
user_id VARCHAR, status_code TINYINT DEFAULT 0,
input_tokens INTEGER, output_tokens INTEGER,
cache_read_tokens INTEGER, cache_write_tokens INTEGER, cost_usd DOUBLE,
attributes JSON, resource_attrs JSON, ingested_at TIMESTAMPTZ DEFAULT now()
)`); err != nil {
t.Fatalf("seed v9 spans: %v", err)
}
for _, idx := range []string{"session_id", "start_time", "name", "user_id"} {
if _, err := raw.Exec(`CREATE INDEX idx_spans_` + idx + ` ON spans(` + idx + `)`); err != nil {
t.Fatalf("seed index on %s: %v", idx, err)
}
}
for i := 0; i < 3; i++ {
if _, err := raw.Exec(`
INSERT INTO spans (trace_id, span_id, name, start_time, end_time, service_name, session_id, model, tool_name, user_id)
VALUES ('t', ?, 'tool.execution', ?, ?, 'claude-code', ?, 'claude-opus-4', 'Bash', ?)`,
fmt.Sprintf("span-%d", i), time.Unix(int64(i), 0), time.Unix(int64(i)+1, 0),
fmt.Sprintf("session-%d", i), fmt.Sprintf("user-%d", i)); err != nil {
t.Fatalf("seed span %d: %v", i, err)
}
}
if err := raw.Close(); err != nil {
t.Fatalf("raw close: %v", err)
}

db, err := Open(path)
if err != nil {
t.Fatalf("open v9 db: %v", err)
}
defer db.Close()
ro := db.ReadOnly()

var cols int
if err := ro.QueryRow(`
SELECT COUNT(*) FROM information_schema.columns
WHERE table_name = 'spans' AND column_name = 'duration_ms'`).Scan(&cols); err != nil {
t.Fatalf("read spans columns: %v", err)
}
if cols != 0 {
t.Errorf("duration_ms still declared on spans after upgrade")
}

var total int
if err := ro.QueryRow(`SELECT COUNT(*) FROM spans`).Scan(&total); err != nil {
t.Fatalf("count spans: %v", err)
}
if total != 3 {
t.Errorf("spans after upgrade = %d, want 3: the migration moved rows", total)
}

var bash int
if err := ro.QueryRow(`SELECT COUNT(*) FROM spans WHERE tool_name = 'Bash'`).Scan(&bash); err != nil {
t.Fatalf("count Bash spans: %v", err)
}
if bash != 3 {
t.Errorf("tool_name = 'Bash' returned %d rows, want 3 on %s: the upgraded layout still traps bare equality",
bash, duckDBVersion(t, ro))
}

var dur float64
if err := ro.QueryRow(`
SELECT CAST(epoch_ms(end_time) - epoch_ms(start_time) AS DOUBLE)
FROM spans WHERE span_id = 'span-0'`).Scan(&dur); err != nil {
t.Fatalf("read computed duration: %v", err)
}
if dur != 1000 {
t.Errorf("computed duration_ms = %v, want 1000", dur)
}
}

func duckDBVersion(t *testing.T, r *ReadDB) string {
t.Helper()
var v string
Expand Down
2 changes: 1 addition & 1 deletion internal/storage/retention.go
Original file line number Diff line number Diff line change
Expand Up @@ -144,7 +144,7 @@ func (db *DB) rollupAndPurgeAt(cfg RetentionConfig, now time.Time) error {
COALESCE(SUM(cache_read_tokens), 0),
COALESCE(SUM(cache_write_tokens), 0),
COALESCE(SUM(cost_usd), 0),
COALESCE(SUM(duration_ms), 0),
COALESCE(SUM(CAST(epoch_ms(end_time) - epoch_ms(start_time) AS DOUBLE)), 0),
COUNT(*) FILTER (WHERE status_code = 2)
FROM spans
WHERE start_time < ?
Expand Down
21 changes: 17 additions & 4 deletions internal/storage/schema.sql
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
-- Schema version: 9
-- Schema version: 10
-- Versioned; never silently rename columns.

CREATE TABLE IF NOT EXISTS schema_version (
Expand All @@ -17,9 +17,6 @@ CREATE TABLE IF NOT EXISTS spans (
-- Timing
start_time TIMESTAMPTZ NOT NULL,
end_time TIMESTAMPTZ NOT NULL,
duration_ms DOUBLE GENERATED ALWAYS AS (
epoch_ms(end_time) - epoch_ms(start_time)
),

-- Service metadata
service_name VARCHAR,
Expand Down Expand Up @@ -55,6 +52,21 @@ ALTER TABLE spans ADD COLUMN IF NOT EXISTS status_code TINYINT DEFAULT 0;
-- Migration v2 → v3: add user_id for multi-user telemetry separation.
ALTER TABLE spans ADD COLUMN IF NOT EXISTS user_id VARCHAR;

-- Migration v9 → v10: drop the derived duration_ms column (ADR-0013). As a
-- VIRTUAL generated column it took a logical slot but no storage slot, so every
-- later column's logical index ran one ahead of its physical index and a bare
-- `col = <constant>` probed an unrelated index and matched nothing. Duration is
-- computed where it is read.
--
-- DuckDB refuses to ALTER a table an index depends on, so the secondary indexes
-- are dropped here and recreated below. Both statements are idempotent, so a
-- re-apply of this file rebuilds the indexes but moves no row data.
DROP INDEX IF EXISTS idx_spans_session_id;
DROP INDEX IF EXISTS idx_spans_start_time;
DROP INDEX IF EXISTS idx_spans_name;
DROP INDEX IF EXISTS idx_spans_user_id;
ALTER TABLE spans DROP COLUMN IF EXISTS duration_ms;

-- Indexes for dashboard hot paths (DuckDB ART indexes).
CREATE INDEX IF NOT EXISTS idx_spans_session_id ON spans(session_id);
CREATE INDEX IF NOT EXISTS idx_spans_start_time ON spans(start_time);
Expand Down Expand Up @@ -144,3 +156,4 @@ INSERT INTO schema_version (version) VALUES (6) ON CONFLICT DO NOTHING;
INSERT INTO schema_version (version) VALUES (7) ON CONFLICT DO NOTHING;
INSERT INTO schema_version (version) VALUES (8) ON CONFLICT DO NOTHING;
INSERT INTO schema_version (version) VALUES (9) ON CONFLICT DO NOTHING;
INSERT INTO schema_version (version) VALUES (10) ON CONFLICT DO NOTHING;