fix(mcp): time-bound trace waterfall queries so they prune partitions - #3116
fix(mcp): time-bound trace waterfall queries so they prune partitions#3116brandon-pereira wants to merge 3 commits into
Conversation
The clickstack_trace_waterfall tool ran TraceId-only span/log queries that scanned the full retention window and timed out. Thread the search window into both queries, add a max_execution_time ceiling, and probe the trace's actual [min, max] span extent so an explicit traceId older than the default window — or one that ran longer than an hour — still resolves in full. The probe also runs for auto-picked traces, so a picked trace whose root predates the window is no longer truncated into a partial tree. The fetch window is width-clamped to the recent tail so a reused/sentinel traceId can't widen the scan back toward the retention edge or stitch unrelated occurrences into one tree. Empty-result hints name the recoverable action (pass an explicit startTime), and probe failures are surfaced rather than silently swallowed. ClickHouse query timeouts are reclassified from user to server errors.
🦋 Changeset detectedLatest commit: eb5b412 The changes in this PR will be included in the next version bump. This PR includes changesets to release 3 packages
Not sure what this means? Click here to learn what changesets are. Click here if you're a maintainer who wants to add another changeset to this PR |
|
The latest updates on your projects. Learn more about Vercel for GitHub.
|
Greptile SummaryThe PR bounds trace-waterfall ClickHouse queries, probes trace extents, enforces shared query timeouts, and improves timeout classification and incomplete-result guidance.
Confidence Score: 3/5The PR is not yet safe to merge because supported multi-column timestamp sources can return incorrect trace data, and auto-picked traces can still be silently truncated after an explicit end time. The bounded-query approach is sound for single timestamp expressions, but selecting a date-only first timestamp token breaks event-time filtering and ordering for supported multi-column sources. The auto-pick probe also searches backward beyond the pick window without searching sufficiently beyond its end, so a later trace tail can be omitted without warning. The previous probe-failure warning was fully fixed; brandon-pereira accepted the bounded late-log risk because arbitrary duration padding would undermine scan limits; the fixed-bound finding was withdrawn after its tradeoff became explicit; and the comment-divider thread was resolved after the newly introduced divider was removed. Files Needing Attention: packages/api/src/mcp/tools/trace/waterfall.ts
|
| Filename | Overview |
|---|---|
| packages/api/src/mcp/tools/trace/waterfall.ts | Adds extent probing and bounded span/log fetches, but mishandles multi-column timestamps and can silently truncate an auto-picked trace after an explicit end time. |
| packages/api/src/mcp/tools/query/helpers.ts | Exports shared ClickHouse limits and correctly classifies and explains execution-time failures. |
| packages/api/src/mcp/tests/trace.int.test.ts | Adds broad integration coverage for bounded trace fetching, though it does not cover a trace tail after an explicit auto-pick end time. |
| packages/api/src/mcp/tests/query.test.ts | Covers timeout classification and protects setting-constraint errors from the timeout hint. |
| .changeset/trace-waterfall-time-bound.md | Records the user-facing trace-waterfall query behavior change as an API patch release. |
Flowchart
%%{init: {'theme': 'neutral'}}%%
flowchart LR
I[Trace waterfall input] --> P{Explicit trace ID?}
P -->|No| A[Pick trace inside search window]
P -->|Yes| E[Use supplied trace ID]
A --> X[Probe bounded span extent]
E --> X
X --> C[Pad and width-clamp fetch window]
C --> S[Fetch bounded spans]
C --> L[Fetch bounded correlated logs]
S --> R[Build trace tree]
L --> R
R --> O[Return waterfall and completeness notes]
Reviews (4): Last reviewed commit: "fix(mcp): address deep-review findings o..." | Re-trigger Greptile
![greptile-apps[bot]](https://avatars.githubusercontent.com/in/867647?s=60&v=4){kind=small}
E2E Test Results✅ All tests passed • 357 passed • 1 skipped • 1503s
Tests ran across 4 shards in parallel. |
- MCP ClickHouse settings now win over source.querySettings so a source can't relax the max_execution_time / readonly ceiling (span + log fetches). - Surface a probeNote when the extent probe fails and the fallback window may return a partial tree, instead of presenting it as complete. - Surface a windowNote when the fetch-window cap drops a wide-spread trace's earliest spans, so the tool no longer silently promises the whole tree. - Drop the newly added "Safety limits" ASCII divider per AGENTS.md.
github-actions
Bot
added
the
review/tier-2
🟡 Tier 3 — StandardIntroduces new logic, modifies core functionality, or touches areas with non-trivial risk. Why this tier:
Review process: Full human review — logic, architecture, edge cases. Stats
|
Deep ReviewScope: Several previously-flagged P1 issues are confirmed resolved in the current tree: the multi-column ✅ No critical (P0/P1) issues found. 🟡 P2 — recommended
🔵 P3 nitpicks (3)
Reviewers (10): correctness, testing, maintainability, project-standards, performance, reliability, adversarial, kieran-typescript, api-contract, previous-comments. Coverage note: testing, maintainability, and project-standards returned before synthesis; the remaining reviewers were still completing, so the P2 performance/probe and log-trail findings and the prior-thread dispositions are drawn from orchestrator analysis of the diff and the 8 prior-comment threads. The 90-day-probe-scan concern corroborates a prior automated review comment that was not clearly addressed. Testing gaps: No test asserts a log outside the fetch window is excluded (only inclusion is tested). The 24h clamp-floor boundary is validated only indirectly via a 10-day gap, so an off-by-window regression near the edge would not be caught. |
![github-actions[bot]](https://avatars.githubusercontent.com/in/15368?s=60&v=4){kind=small}
| 'The result row count is too large to serialize back to the agent.' | ||
| ); | ||
| } | ||
| if (/TIMEOUT_EXCEEDED|Timeout exceeded|max_execution_time/i.test(msg)) { |
There was a problem hiding this comment.
🟠 major — New timeout hint matches max_execution_time anywhere in the message, so it hijacks SETTING_CONSTRAINT_VIOLATION and READONLY errors
The regex /TIMEOUT_EXCEEDED|Timeout exceeded|max_execution_time/i runs before the SETTING_CONSTRAINT_VIOLATION branch at line 934. ClickHouse's constraint error reads Setting max_execution_time shouldn't be greater than 10. (SETTING_CONSTRAINT_VIOLATION) and the readonly error reads Cannot modify 'max_execution_time' setting in readonly mode — both now return "The query exceeded its execution-time limit. Narrow the time range…", sending the agent into a pointless narrow-and-retry loop instead of telling it the connection profile caps the setting. This is newly reachable precisely because this PR forces max_execution_time: 30 onto every waterfall query too. Drop max_execution_time from the alternation (keep TIMEOUT_EXCEEDED|Timeout exceeded), or move the branch below the SETTING_CONSTRAINT_VIOLATION check. The existing test at packages/api/src/mcp/__tests__/query.test.ts:43 only uses max_result_rows, so it doesn't catch this.
There was a problem hiding this comment.
Fixed — dropped the bare max_execution_time from the timeout-hint alternation (kept TIMEOUT_EXCEEDED|Timeout exceeded), so a Setting max_execution_time shouldn't be greater than… error now falls through to the SETTING_CONSTRAINT_VIOLATION branch. Added a regression test asserting a max_execution_time constraint error gets the constraint hint, not the timeout hint.
| const probeQuery = ` | ||
| SELECT | ||
| min(${params.tsExpr}) AS firstSeen, | ||
| max(${params.tsExpr}) AS lastSeen |
There was a problem hiding this comment.
🟠 major — timestampValueExpression is interpolated unsplit into min()/max() and a comparison, breaking multi-column timestamp sources
timestampValueExpression may hold a comma-separated list (e.g. 'EventDate, EventTime' — see getFirstTimestampValueExpression in packages/common-utils/src/core/utils.ts:151, and the many configs in packages/common-utils/src/__tests__/renderChartConfig.test.ts:3931). The pre-PR query tolerated that because ${tsExpr} only appeared in SELECT … AS timestamp and ORDER BY; the new uses do not — min(EventDate, EventTime) fails arity validation and WHERE EventDate, EventTime >= fromUnixTimestamp64Milli(…) is a syntax error, so the probe throws and the tree query then returns a hard ClickHouse error for every call. Wrap both tsExpr (line 362) and logTsExpr (line 650) in getFirstTimestampValueExpression from @hyperdx/common-utils/dist/core/utils, which is already imported in the sibling packages/api/src/mcp/tools/query/helpers.ts:8.
There was a problem hiding this comment.
Good catch — fixed. Both tsExpr and logTsExpr are now wrapped in getFirstTimestampValueExpression for every raw-SQL use (probe min/max, tree SELECT/WHERE/ORDER BY, picker min/max orderBy, log SELECT/WHERE/ORDER BY). The full multi-column expression is kept only where queryChartConfig consumes it (it splits internally).
| let fetchEnd = endDate; | ||
| let probeFailed = false; | ||
| let windowClamped = false; | ||
| const usedDefaultWindow = input.startTime == null; |
There was a problem hiding this comment.
🟠 major — Auto-pick with an explicit startTime skips the probe, so the fetch now silently truncates the tree
usedDefaultWindow = input.startTime == null gates the probe, but in auto-pick mode startTime is the pick window ("find me a slow trace from the last hour"), not a fetch bound. Before this PR the span query was unbounded so the whole tree came back; now a caller passing pickFilter + startTime: <1h ago> gets only the in-window spans of the picked trace — a false rootSpan, an understated totalDurationMs, and no probeNote/windowNote to signal it. That is the exact failure the PR description cites as the reason for probing in auto-pick mode. Gate on input.traceId == null || input.startTime == null so auto-pick always probes (the explicit-traceId + explicit-window honoring that trace.int.test.ts:488 pins is unaffected).
There was a problem hiding this comment.
Fixed — the probe now runs whenever input.traceId == null (auto-pick) OR input.startTime == null, so auto-pick with an explicit pick-window startTime still probes the picked trace's real extent. The only path that honors the window verbatim is explicit traceId + explicit startTime (pinned by the existing test). Added an integration test for auto-pick + explicit startTime with a root predating the window.
| const usedDefaultWindow = input.startTime == null; | ||
| if (usedDefaultWindow) { | ||
| const probeStart = input.traceId | ||
| ? new Date(endDate.getTime() - TRACE_PROBE_MAX_LOOKBACK_MS) |
There was a problem hiding this comment.
🔵 minor — The probe re-runs the same unpruned 90-day TraceId scan the PR is trying to eliminate
For an explicit traceId the probe runs WHERE TraceId = X AND ts BETWEEN now-90d AND now — the same predicate shape, over a range that equals or exceeds the retention window on most deployments, so it cannot prune partitions either. On the deployments this PR targets the probe is what will now hit the new max_execution_time: 30 ceiling, leaving the caller with probeFailed plus an empty fallback window. Probe with a widening ladder instead (e.g. 1h → 24h → 7d → 90d, stopping at the first hit) so the common recent-trace case touches one or two partitions.
There was a problem hiding this comment.
Valid observation, but deferring: a widening ladder (1h → 24h → 7d → 90d) is a meaningful redesign with its own tradeoffs (extra round-trips for genuinely old traces, tuning the rungs), and the probe now carries the same max_execution_time ceiling, so a probe timeout degrades gracefully to probeFailed + an accurate hint rather than a hang. The common recent-trace case already prunes to a narrow window once the extent is found. Worth a follow-up if probe latency shows up in practice; out of scope for this fix.
| // first-seen — so a trace whose spans span more than an hour is returned | ||
| // whole, spans and correlated logs alike. | ||
| describe('long-running trace window', () => { | ||
| const LONG_TRACE_ID = 'aaaa1111bbbb2222cccc3333dddd4444'; |
There was a problem hiding this comment.
🔵 minor — LONG_TRACE_ID reuses the breakdown suite's TRACE_ID_1 in a table that is never truncated
'aaaa1111bbbb2222cccc3333dddd4444' is already used as TRACE_ID_1 at line 953, and clearClickhouseTables in packages/api/src/fixtures.ts:380 has the traces table commented out — the comment at line 951 warns about exactly this. The new test only passes because it runs first in declaration order; under --randomize, or if either describe is moved, the breakdown suite's three recent spans join the probe's [min, max], the 2-day spread trips the 24h clamp, and the test fails on spanCount/windowNote. Give it a unique id.
There was a problem hiding this comment.
Fixed — gave LONG_TRACE_ID a unique value so it no longer collides with the breakdown suite's TRACE_ID_1 in the never-cleared traces table.
PR Review4 finding(s): 🔴 0 critical · 🟠 2 major · 🔵 2 minor 3 posted as inline comment(s) on the changed lines. 1 listed below. Findings outside the changed lines
Severity is the reviewer's own estimate and is used for ordering, not filtering. |
- errorHint: match only real timeouts (TIMEOUT_EXCEEDED / "Timeout exceeded") so a "Setting max_execution_time shouldn't be greater than…" constraint error no longer hijacks the timeout hint. Regression test added. - Wrap tsExpr / logTsExpr in getFirstTimestampValueExpression for every raw-SQL use (probe min/max, tree + log SELECT/WHERE/ORDER BY, picker orderBy) so a multi-column timestampValueExpression (e.g. "EventDate, EventTime") no longer breaks the probe and span queries. - Probe in auto-pick mode even with an explicit startTime: startTime is the pick window there, not a fetch bound, so the picked trace's full extent must still be probed. Only explicit traceId + explicit startTime honors the window verbatim. Integration test added. - Give LONG_TRACE_ID a unique value so it no longer collides with the breakdown suite's TRACE_ID_1 in the never-cleared traces table.
github-actions
Bot
added
review/tier-3
| // "EventDate, EventTime"). Raw-SQL uses that aggregate or compare on it — | ||
| // min()/max() and the WHERE bounds — need a single column; only the | ||
| // queryChartConfig picker (which splits it itself) gets the full form. | ||
| const tsExprFirst = getFirstTimestampValueExpression(tsExpr); |
There was a problem hiding this comment.
For supported timestamp expressions such as EventDate, EventTime, this uses the first, date-only partition column as the event timestamp. The probe and span fetch therefore calculate extents, filter, order, and return timestamps at day precision. This can exclude valid spans at window boundaries, misorder the tree, and report midnight instead of the actual span time. The log query and first_error ordering have the same problem. Use the precise DateTime expression for event semantics while retaining all configured timestamp columns for partition pruning.
| startDate: probeStart, | ||
| endDate, |
There was a problem hiding this comment.
In auto-pick mode, an explicit endTime limits the search for a trace, not the full-trace fetch. However, the extent probe also stops at endTime. If the selected trace has descendant spans more than one hour after that boundary, they cannot contribute to lastSeen and are omitted from the fetch. None of the current notes warns that the returned tree is incomplete, even though the code recognizes that a trace tail may lie outside the search window.
| // "EventDate, EventTime"). Raw-SQL uses that aggregate or compare on it — | ||
| // min()/max() and the WHERE bounds — need a single column; only the | ||
| // queryChartConfig picker (which splits it itself) gets the full form. | ||
| const tsExprFirst = getFirstTimestampValueExpression(tsExpr); |
There was a problem hiding this comment.
🟠 major — getFirstTimestampValueExpression picks a day-precision column for composite timestamp sources, so the probe window is anchored at midnight and correlated logs come back empty
For a source whose timestampValueExpression is the supported composite "EventDate, EventTime" form, getFirstTimestampValueExpression returns EventDate — a Date column. The probe then computes min(EventDate)/max(EventDate), so firstSeen/lastSeen are midnight of the trace's day and the fetch window becomes [midnight-1h, midnight+1h]. The span query still matches (it compares the same EventDate), but (a) ${tsExprFirst} AS timestamp now returns midnight for every span, where the pre-diff ${tsExpr} AS timestamp rendered EventDate, EventTime AS timestamp and yielded the real EventTime — so buildPreOrderTree's timestamp sort and the emitted timestamp field silently degrade to day precision; and (b) the log query at line 703 compares the log source's own column against that midnight-anchored window, so a trace that ran at 14:00 returns logs: [] with no note. The mirror case (single-column trace source, composite log source) fails the same way: logTsExpr = EventDate is compared against a precise [13:00, 15:00] window and matches nothing. packages/app/src/utils/rowTimestamps.ts:44-48 spells out exactly this hazard. Use the canonical resolver pickBucketTimestampColumn (packages/common-utils/src/core/utils.ts:205) — it picks the highest-precision DateTime token and skips Date ones; metadata is already built at waterfall.ts:355, and the same fix applies to logTsExpr at line 664.
| }, | ||
| format: 'JSONEachRow', | ||
| connectionId: params.connectionId, | ||
| clickhouse_settings: MCP_CLICKHOUSE_SETTINGS, |
There was a problem hiding this comment.
🔵 minor — Probe query drops source.querySettings that every other query on this path applies
probeTraceWindow sends clickhouse_settings: MCP_CLICKHOUSE_SETTINGS alone, while the pick (line 435), span (line 560) and log (line 722) queries all merge source.querySettings. A source that needs a connection-specific setting to query its table at all will have the probe throw, silently setting probeFailed and falling back to the 15-minute default window — the very failure the probe exists to prevent. Merge source.querySettings under MCP_CLICKHOUSE_SETTINGS here too, matching the span fetch.
| return { | ||
| start: new Date(fetchStart), | ||
| end: new Date(fetchEnd), | ||
| clamped: unclampedStart < clampFloor, |
There was a problem hiding this comment.
🔵 minor — clamped is set for traces whose extent is 22–24h even though no span was actually dropped
clamped: unclampedStart < clampFloor is true whenever lastSeen - firstSeen > 22h (the two 1h pads), but spans are only lost when firstSeen < fetchStart, i.e. when the extent exceeds 23h. For a trace spanning 22.5h the response carries the windowNote claiming "the earliest spans may be missing" while the tree is complete, pushing the agent to re-run with an explicit startTime for nothing. Set clamped: firstSeen < fetchStart instead.
1 participant
Why
clickstack_trace_waterfallfetched a trace's spans and correlated logs with aWHERE TraceId = Xpredicate and no time bound. Because the trace tables partition by day, a TraceId-only query can't prune partitions — it scans the full retention window and hitsmax_execution_time, so the tool times out on any deployment with meaningful history.Naively adding the tool's default 15-minute search window as the bound would fix the scan but break correctness: a trace older than 15 minutes (or picked by
pickBywith a root that predates the window) would return zero or partial spans.What
Thread a real time bound into the span and log queries so ClickHouse prunes partitions, without dropping valid traces:
[min, max]span extent before fetching, and use that (padded) as the window. Cost scales with the one trace, not the retention window. This rescues an explicittraceIdolder than the default window and keeps a trace that ran longer than an hour from being truncated.traceId(e.g. an all-zero id from an uninstrumented emitter) whoseminandmaxare days apart can't balloon the scan back toward the retention edge or stitch two unrelated occurrences into one nonsense tree. When the clamp drops early spans, the response carries awindowNoterather than silently promising the whole tree.max_execution_timeceiling + HTTP request timeout shared with the rest of the MCP query tools (constants exported fromquery/helpers.tsrather than duplicated). The ceiling takes precedence oversource.querySettings, so a source can't relax it.startTime") instead of the misleading "widen the window" — the caller never set a window to widen. A probe that fails on infrastructure error is surfaced (probeNote), not silently swallowed.TIMEOUT_EXCEEDED) fromusertoservererrors, with an actionable error hint. A query hitting the execution-time limit is a resource failure, not a user mistake, and theuserdefault hid these from error views.Testing
query.test.ts):TIMEOUT_EXCEEDEDclassification + error-hint text.trace.int.test.ts): probe rescue of an old trace, explicit-window honoring, probe-miss hint, wide-spread sentinel clamp (withwindowNote), >1h-spread trace, and auto-pick root predating the window.