From c346154882a0bbcfe338cf969a03b2116f435c40 Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Fri, 11 Sep 2026 16:38:07 -0600 Subject: [PATCH 01/10] fix(mcp): time-bound trace waterfall queries so they prune partitions MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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/trace-waterfall-time-bound.md | 19 ++ packages/api/src/mcp/__tests__/query.test.ts | 20 ++ .../api/src/mcp/__tests__/trace.int.test.ts | 282 ++++++++++++++++++ packages/api/src/mcp/tools/query/helpers.ts | 32 +- packages/api/src/mcp/tools/trace/waterfall.ts | 174 ++++++++++- 5 files changed, 510 insertions(+), 17 deletions(-) create mode 100644 .changeset/trace-waterfall-time-bound.md diff --git a/.changeset/trace-waterfall-time-bound.md b/.changeset/trace-waterfall-time-bound.md new file mode 100644 index 0000000000..b55df8f6bc --- /dev/null +++ b/.changeset/trace-waterfall-time-bound.md @@ -0,0 +1,19 @@ +--- +"@hyperdx/api": patch +--- + +fix(mcp): time-bound the trace waterfall span/log fetches so they prune +partitions instead of scanning the full retention window. The +`clickstack_trace_waterfall` tool now threads the search window into its span +and correlated-log queries, adds a `max_execution_time` ceiling, and probes a +trace's `[min, max]` span extent so an explicit `traceId` older than the +default window — or a trace 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 or sentinel `traceId` (e.g. an +all-zero id from an uninstrumented emitter) can't widen the scan back toward the +retention edge or stitch unrelated occurrences into one tree. Empty-result hints +now name the recoverable action (pass an explicit `startTime`) instead of the +misleading "widen the window", and a probe that fails is surfaced rather than +silently swallowed. ClickHouse query timeouts are also reclassified from `user` +to `server` errors. diff --git a/packages/api/src/mcp/__tests__/query.test.ts b/packages/api/src/mcp/__tests__/query.test.ts index a404a831c3..7befc707be 100644 --- a/packages/api/src/mcp/__tests__/query.test.ts +++ b/packages/api/src/mcp/__tests__/query.test.ts @@ -300,6 +300,15 @@ describe('errorHint', () => { expect(hint).toContain('too many rows'); }); + it('should match TIMEOUT_EXCEEDED errors', () => { + const hint = errorHint( + 'Code: 159. DB::Exception: Timeout exceeded: elapsed 30s (TIMEOUT_EXCEEDED)', + ); + expect(hint).not.toBeNull(); + expect(hint).toContain('execution-time limit'); + expect(hint).toContain('Narrow the time range'); + }); + it('should match SETTING_CONSTRAINT_VIOLATION errors', () => { const hint = errorHint( "Setting max_result_rows shouldn't be greater than 1000. (SETTING_CONSTRAINT_VIOLATION)", @@ -416,6 +425,17 @@ describe('isServerError', () => { expect(isServerError(err)).toBe(false); }); + it('returns true for TIMEOUT_EXCEEDED (max_execution_time overrun)', () => { + // Query timeouts are a resource failure, not a user mistake. + const cause = new ClickHouseError({ + message: 'Timeout exceeded: elapsed 30s', + code: '159', + type: 'TIMEOUT_EXCEEDED', + }); + const err = new Error('query failed', { cause }); + expect(isServerError(err)).toBe(true); + }); + it('returns true for ECONNREFUSED (TCP connection failure)', () => { const err = Object.assign(new Error('connect ECONNREFUSED 127.0.0.1:1'), { code: 'ECONNREFUSED', diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index e2187e8932..d3d1b7cab5 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -432,6 +432,288 @@ describe('MCP Trace Tools', () => { }); }); + // The span/log fetches are time-bounded for partition pruning. + // Pins both edges — the bound is honored, yet an explicit traceId older + // than the default window is still rescued by the first-seen probe. + describe('time-bounding', () => { + const OLD_TRACE_ID = 'dead0000beef1111cafe2222f00d3333'; + const OLD_SVC = 'wf-oldtrace-svc'; + const now = new Date(); + // Two days old — far outside the default 15-minute window, but within the + // probe's 90-day widened range. + const twoDaysAgo = new Date(now.getTime() - 2 * 24 * 60 * 60 * 1000); + + beforeEach(async () => { + await bulkInsertTraces([ + { + Timestamp: twoDaysAgo, + TraceId: OLD_TRACE_ID, + SpanId: 'old_root_span01', + ParentSpanId: '', + SpanName: 'GET /wf-old/root', + SpanKind: 'SPAN_KIND_SERVER', + ServiceName: OLD_SVC, + Duration: 300_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + { + Timestamp: new Date(twoDaysAgo.getTime() + 10), + TraceId: OLD_TRACE_ID, + SpanId: 'old_child_span1', + ParentSpanId: 'old_root_span01', + SpanName: 'wf-old-child', + SpanKind: 'SPAN_KIND_CLIENT', + ServiceName: OLD_SVC, + Duration: 100_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + ]); + }); + + it('resolves an explicit traceId older than the default window via the first-seen probe', async () => { + // No startTime/endTime: the 15-min default excludes this 2-day-old + // trace, so only the probe can rescue it. + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + traceId: OLD_TRACE_ID, + includeLogs: false, + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + expect(output.traceId).toBe(OLD_TRACE_ID); + expect(output.spanCount).toBe(2); + }); + + it('honors an explicit window that excludes the trace (returns no-spans hint)', async () => { + // Explicit window the old trace falls outside of: no spans come back, + // proving the time predicate is applied rather than ignored. + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + traceId: OLD_TRACE_ID, + includeLogs: false, + startTime: new Date(now.getTime() - 10 * 60 * 1000).toISOString(), + endTime: new Date(now.getTime() + 60 * 1000).toISOString(), + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + expect(output.result).toBeNull(); + expect(output.hint).toContain('widen the window'); + }); + + it('points an explicit-traceId miss at startTime, not "widen the window"', async () => { + // A traceId that does not exist: the default window is probed back 90 + // days, finds nothing, and the hint must name the recoverable action + // (pass an explicit startTime) rather than the auto-pick advice. + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + traceId: 'ffffffffffffffffffffffffffffffff', + includeLogs: false, + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + expect(output.result).toBeNull(); + expect(output.hint).toContain('90 days'); + expect(output.hint).toContain('startTime'); + }); + }); + + // A reused/sentinel TraceId (e.g. an all-zero id from an uninstrumented + // emitter) can have occurrences days apart. The probe's [min, max] window + // is width-clamped to the recent tail so the fetch stays bounded — it must + // NOT balloon back toward the 90-day probe range or stitch the old and new + // occurrences into one nonsense tree. + describe('wide-spread TraceId window clamp', () => { + const SENTINEL_TRACE_ID = '00000000000000000000000000000000'; + const SENTINEL_SVC = 'wf-sentinel-svc'; + const now = new Date(); + const tenDaysAgo = new Date(now.getTime() - 10 * 24 * 60 * 60 * 1000); + const fiveMinAgo = new Date(now.getTime() - 5 * 60 * 1000); + + beforeEach(async () => { + await bulkInsertTraces([ + // Old occurrence — outside the 24h clamp off the recent tail. + { + Timestamp: tenDaysAgo, + TraceId: SENTINEL_TRACE_ID, + SpanId: 'sentinel_old_span', + ParentSpanId: '', + SpanName: 'GET /sentinel/old', + SpanKind: 'SPAN_KIND_SERVER', + ServiceName: SENTINEL_SVC, + Duration: 100_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + // Recent occurrence — a distinct 2-span tree. + { + Timestamp: fiveMinAgo, + TraceId: SENTINEL_TRACE_ID, + SpanId: 'sentinel_new_root', + ParentSpanId: '', + SpanName: 'GET /sentinel/new', + SpanKind: 'SPAN_KIND_SERVER', + ServiceName: SENTINEL_SVC, + Duration: 200_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + { + Timestamp: new Date(fiveMinAgo.getTime() + 10), + TraceId: SENTINEL_TRACE_ID, + SpanId: 'sentinel_new_child', + ParentSpanId: 'sentinel_new_root', + SpanName: 'sentinel-new-child', + SpanKind: 'SPAN_KIND_CLIENT', + ServiceName: SENTINEL_SVC, + Duration: 50_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + ]); + }); + + it('clamps the fetch window to the recent tail, excluding the far-past occurrence', async () => { + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + traceId: SENTINEL_TRACE_ID, + includeLogs: false, + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + // Only the recent 2-span occurrence is returned; the 10-day-old span is + // outside the clamped window, so it is not stitched into the tree. + expect(output.spanCount).toBe(2); + expect(output.spans.map((s: any) => s.spanId)).not.toContain( + 'sentinel_old_span', + ); + expect(output.spans.filter((s: any) => s.depth === 0)).toHaveLength(1); + }); + }); + + // The probe fetches the trace's [min, max] extent, not a fixed lead off + // 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'; + const LONG_SVC = 'wf-longtrace-svc'; + const now = new Date(); + // Root two days ago; a child span ~2h later. A fixed first-seen + 1h lead + // would truncate that child; the [min, max] probe keeps it. + const rootTs = new Date(now.getTime() - 2 * 24 * 60 * 60 * 1000); + const lateTs = new Date(rootTs.getTime() + 2 * 60 * 60 * 1000); + + beforeEach(async () => { + await bulkInsertTraces([ + { + Timestamp: rootTs, + TraceId: LONG_TRACE_ID, + SpanId: 'long_root_span01', + ParentSpanId: '', + SpanName: 'GET /wf-long/root', + SpanKind: 'SPAN_KIND_SERVER', + ServiceName: LONG_SVC, + Duration: 7_200_000_000_000, // ~2h in ns + StatusCode: 'STATUS_CODE_OK', + }, + { + Timestamp: lateTs, + TraceId: LONG_TRACE_ID, + SpanId: 'long_late_span01', + ParentSpanId: 'long_root_span01', + SpanName: 'wf-long-late-child', + SpanKind: 'SPAN_KIND_CLIENT', + ServiceName: LONG_SVC, + Duration: 100_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + ]); + await bulkInsertLogs([ + { + Timestamp: lateTs, + TraceId: LONG_TRACE_ID, + SpanId: 'long_late_span01', + Body: 'late log line', + ServiceName: LONG_SVC, + SeverityText: 'INFO', + }, + ]); + }); + + it('returns the full tree and a late log for a trace spanning > 1h', async () => { + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + traceId: LONG_TRACE_ID, + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + expect(output.traceId).toBe(LONG_TRACE_ID); + expect(output.spanCount).toBe(2); + expect(output.spans.filter((s: any) => s.depth === 0)).toHaveLength(1); + // A fixed first-seen + 1h lead would have cut off this late child's log. + expect(output.logsCount).toBe(1); + }); + }); + + // Auto-pick is also probed: a picked trace is only guaranteed one span in + // the default window, so its root/tail can lie outside it. + describe('auto-pick window', () => { + const PICK_TRACE_ID = 'bbbb2222cccc3333dddd4444eeee5555'; + const PICK_SVC = 'wf-autopick-old-svc'; + const now = new Date(); + // Root predates the default 15-min window; a child is inside it. Auto-pick + // finds the trace via the in-window child, but the fetch must cover the + // out-of-window root too. + const rootTs = new Date(now.getTime() - 40 * 60 * 1000); + const childTs = new Date(now.getTime() - 5 * 60 * 1000); + + beforeEach(async () => { + await bulkInsertTraces([ + { + Timestamp: rootTs, + TraceId: PICK_TRACE_ID, + SpanId: 'pick_root_span01', + ParentSpanId: '', + SpanName: 'GET /wf-autopick/root', + SpanKind: 'SPAN_KIND_SERVER', + ServiceName: PICK_SVC, + Duration: 2_400_000_000_000, // 40m in ns → picked as slowest + StatusCode: 'STATUS_CODE_OK', + }, + { + Timestamp: childTs, + TraceId: PICK_TRACE_ID, + SpanId: 'pick_child_span1', + ParentSpanId: 'pick_root_span01', + SpanName: 'wf-autopick-child', + SpanKind: 'SPAN_KIND_CLIENT', + ServiceName: PICK_SVC, + Duration: 100_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + ]); + }); + + it('returns the whole tree when the picked trace root predates the window', async () => { + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + pickFilter: `ServiceName:${PICK_SVC}`, + pickBy: 'slowest', + includeLogs: false, + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + expect(output.traceId).toBe(PICK_TRACE_ID); + // Without the auto-pick probe, only the in-window child would return, + // producing a false root and a spanCount of 1. + expect(output.spanCount).toBe(2); + expect(output.spans.filter((s: any) => s.depth === 0)).toHaveLength(1); + expect(output.rootSpan.spanId).toBe('pick_root_span01'); + }); + }); + describe('first_error pick mode', () => { const ERROR_TRACE_ID = 'ffff0000eeee1111dddd2222cccc3333'; const now = new Date(); diff --git a/packages/api/src/mcp/tools/query/helpers.ts b/packages/api/src/mcp/tools/query/helpers.ts index 8743c88fb0..b5b7eaa96e 100644 --- a/packages/api/src/mcp/tools/query/helpers.ts +++ b/packages/api/src/mcp/tools/query/helpers.ts @@ -1,4 +1,7 @@ -import { ClickHouseError } from '@clickhouse/client-common'; +import { + ClickHouseError, + type ClickHouseSettings, +} from '@clickhouse/client-common'; import { getMetadata } from '@hyperdx/common-utils/dist/core/metadata'; import { convertToCategoricalChartConfig, @@ -69,19 +72,18 @@ export const SAFE_BODY_EXPR_CHARS = /^[\w.':\[\]\-]+$/; // ─── Safety limits ─────────────────────────────────────────────────────────── /** ClickHouse settings applied to all MCP query-tool executions. - * readonly=2 so max_execution_time can be set - * (readonly=1 rejects all setting changes). */ -const MCP_CLICKHOUSE_SETTINGS = { + * readonly=2 so max_execution_time can be set (readonly=1 rejects it). */ +export const MCP_CLICKHOUSE_SETTINGS: ClickHouseSettings = { max_execution_time: 30, - readonly: 2, -} as const; + readonly: '2', +}; /** - * HTTP request timeout for MCP query-tool ClickHouse clients. - * Set slightly above max_execution_time so ClickHouse can return a clean - * timeout error before the HTTP connection is aborted. + * HTTP request timeout for MCP query-tool ClickHouse clients. Set above + * max_execution_time so ClickHouse returns a clean timeout before the HTTP + * connection is aborted. */ -const MCP_REQUEST_TIMEOUT = 32_000; // 30s query limit + 2s buffer +export const MCP_REQUEST_TIMEOUT = 32_000; // 30s query limit + 2s buffer // ─── Increase top-N cap hint ──────────────────────────────────────────────── @@ -686,6 +688,9 @@ const SERVER_CH_ERROR_TYPES = new Set([ 'SOCKET_TIMEOUT', 'POCO_EXCEPTION', 'ALL_CONNECTION_TRIES_FAILED', + // A query hitting max_execution_time is a resource failure, not a user + // mistake; the `user` default hid these in error views. + 'TIMEOUT_EXCEEDED', ]); /** @@ -903,6 +908,13 @@ export function errorHint(msg: string, error?: unknown): string | null { 'The result row count is too large to serialize back to the agent.' ); } + if (/TIMEOUT_EXCEEDED|Timeout exceeded|max_execution_time/i.test(msg)) { + return ( + 'The query exceeded its execution-time limit. Narrow the time range so ' + + 'ClickHouse can prune partitions, add filters to reduce the rows scanned, ' + + 'or lower the requested LIMIT.' + ); + } if (/TOO_MANY_ROWS_OR_BYTES|RESULT_IS_TOO_LARGE/i.test(msg)) { return ( 'The query returned too many rows. ' + diff --git a/packages/api/src/mcp/tools/trace/waterfall.ts b/packages/api/src/mcp/tools/trace/waterfall.ts index 979a406f73..9678d4b26c 100644 --- a/packages/api/src/mcp/tools/trace/waterfall.ts +++ b/packages/api/src/mcp/tools/trace/waterfall.ts @@ -12,6 +12,8 @@ import { getConnectionById } from '@/controllers/connection'; import { getSource } from '@/controllers/sources'; import { clickHouseErrorResult, + MCP_CLICKHOUSE_SETTINGS, + MCP_REQUEST_TIMEOUT, parseTimeRange, } from '@/mcp/tools/query/helpers'; import type { ToolRegistrar } from '@/mcp/tools/types'; @@ -31,8 +33,10 @@ const traceSchema = z.object({ .optional() .describe( 'Specific TraceId to look up. When provided, the tool fetches every span ' + - 'in this trace and returns them as a parent/child tree. ' + - 'When omitted, the tool auto-picks one trace using pickFilter + pickBy.', + 'in this trace and returns them as a parent/child tree. When omitted, ' + + 'the tool auto-picks one trace using pickFilter + pickBy. With an ' + + 'explicit traceId and no startTime, the tool probes the trace back to ' + + '90 days; pass startTime only to reach a trace older than that.', ), pickFilter: z .string() @@ -65,7 +69,10 @@ const traceSchema = z.object({ .string() .optional() .describe( - 'Start of the search window as ISO 8601. Default: 15 minutes ago.', + 'Start of the search window as ISO 8601. Default: 15 minutes ago for ' + + 'auto-pick. When traceId is set, the window is instead derived from ' + + "the trace's own span timestamps (probed back to 90 days), so pass " + + 'startTime only to look up a trace older than 90 days.', ), endTime: z .string() @@ -106,6 +113,25 @@ const traceSchema = z.object({ type TraceInput = z.infer; +// ─── Safety limits ─────────────────────────────────────────────────────────── + +// Probe-window tuning. The span/log fetch is time-bounded to the +// trace's probed [min, max] extent so ClickHouse prunes partitions. The pads +// absorb clock skew between emitters; they do NOT cover trace duration — the +// [min, max] extent already does. MAX_FETCH_WINDOW clamps the width so a +// reused/sentinel id (e.g. an all-zero TraceId) whose min and max are days +// apart can't widen the scan back toward the retention edge or stitch two +// occurrences into one tree. A trace older than these bounds needs an explicit +// startTime. +const TRACE_PROBE_LEAD_PAD_MS = 1 * 60 * 60 * 1000; +const TRACE_PROBE_TRAIL_PAD_MS = 1 * 60 * 60 * 1000; +const TRACE_PROBE_MAX_LOOKBACK_MS = 90 * 24 * 60 * 60 * 1000; +const TRACE_MAX_FETCH_WINDOW_MS = 24 * 60 * 60 * 1000; + +// Auto-pick guarantees only one span inside the default window; the root can +// predate it, so probe a bounded distance before startDate to cover it. +const TRACE_PROBE_AUTOPICK_LOOKBACK_MS = 6 * 60 * 60 * 1000; + // ─── Helpers ───────────────────────────────────────────────────────────────── type SpanRow = { @@ -164,6 +190,77 @@ function durationDivisor(precision: number): number { return Math.pow(10, Math.max(0, precision - 3)); } +// ClickHouse renders min()/max() over an empty set as the epoch / a zero date. +function parseProbeTimestamp(value: string | undefined): number | null { + if (!value) return null; + const ms = new Date(value).getTime(); + return isNaN(ms) || ms <= 0 ? null : ms; +} + +/** + * Probe a trace's [min, max] span timestamps within [startDate, endDate] and + * return a fetch window covering that extent (padded, then width-clamped). + * Rescues explicit `traceId` lookups older than the default 15-minute window + * and keeps a long trace from being truncated by a fixed lead. The probe is + * time-bounded so it prunes partitions; the caller sets [startDate, endDate]. + * + * Returns null when no span is found, so the caller falls back to its window. + */ +async function probeTraceWindow( + clickhouseClient: ClickhouseClient, + params: { + databaseName: string; + tableName: string; + connectionId: string; + traceIdExpr: string; + tsExpr: string; + traceId: string; + startDate: Date; + endDate: Date; + }, +): Promise<[Date, Date] | null> { + const probeQuery = ` + SELECT + min(${params.tsExpr}) AS firstSeen, + max(${params.tsExpr}) AS lastSeen + FROM {db:Identifier}.{tbl:Identifier} + WHERE ${params.traceIdExpr} = {tid:String} + AND ${params.tsExpr} >= fromUnixTimestamp64Milli({startMs:Int64}) + AND ${params.tsExpr} <= fromUnixTimestamp64Milli({endMs:Int64}) + `; + const result = await clickhouseClient.query({ + query: probeQuery, + query_params: { + db: params.databaseName, + tbl: params.tableName, + tid: params.traceId, + startMs: params.startDate.getTime(), + endMs: params.endDate.getTime(), + }, + format: 'JSONEachRow', + connectionId: params.connectionId, + clickhouse_settings: MCP_CLICKHOUSE_SETTINGS, + }); + const rows = + (await ( + result as { + json: () => Promise<{ firstSeen: string; lastSeen: string }[]>; + } + ).json()) ?? []; + const firstSeen = parseProbeTimestamp(rows[0]?.firstSeen); + const lastSeen = parseProbeTimestamp(rows[0]?.lastSeen); + if (firstSeen == null || lastSeen == null) return null; + + const fetchEnd = lastSeen + TRACE_PROBE_TRAIL_PAD_MS; + // Anchor to the recent tail and clamp the width so a wide-spread/reused + // TraceId can't balloon the fetch back toward the 90-day probe range. + const fetchStart = Math.max( + firstSeen - TRACE_PROBE_LEAD_PAD_MS, + fetchEnd - TRACE_MAX_FETCH_WINDOW_MS, + ); + return [new Date(fetchStart), new Date(fetchEnd)]; +} + // ─── Tool definition ───────────────────────────────────────────────────────── export function registerTraceWaterfall({ @@ -246,6 +343,7 @@ export function registerTraceWaterfall({ host: connection.host, username: connection.username, password: connection.password, + requestTimeout: MCP_REQUEST_TIMEOUT, }); const metadata = getMetadata(clickhouseClient); @@ -363,6 +461,41 @@ export function registerTraceWaterfall({ pickedTraceId = String(candidate[1]); } + // The fetch must be time-bounded so ClickHouse prunes partitions, but the + // default 15-min window is too narrow: an explicit traceId may be older + // than it, and an auto-picked trace is only guaranteed one span inside it + // (its root/tail can lie outside, giving a partial tree). So when the + // window was defaulted, probe the trace's real [min, max] extent instead. + let fetchStart = startDate; + let fetchEnd = endDate; + let probeFailed = false; + const usedDefaultWindow = input.startTime == null; + if (usedDefaultWindow) { + const probeStart = input.traceId + ? new Date(endDate.getTime() - TRACE_PROBE_MAX_LOOKBACK_MS) + : new Date(startDate.getTime() - TRACE_PROBE_AUTOPICK_LOOKBACK_MS); + try { + const probed = await probeTraceWindow(clickhouseClient, { + databaseName: source.from.databaseName, + tableName: source.from.tableName, + connectionId: source.connection.toString(), + traceIdExpr, + tsExpr, + traceId: pickedTraceId, + startDate: probeStart, + endDate, + }); + if (probed) { + [fetchStart, fetchEnd] = probed; + } + } catch { + // probeTraceWindow returns null (not throws) for the empty case, so a + // throw means the probe genuinely didn't complete. The fallback window + // will likely also come back empty, so flag it for an accurate hint. + probeFailed = true; + } + } + // ── Step 2: fetch the full span tree ── const treeQuery = ` SELECT @@ -378,6 +511,8 @@ export function registerTraceWaterfall({ ${attrsExpr} AS spanAttributes FROM {db:Identifier}.{tbl:Identifier} WHERE ${traceIdExpr} = {tid:String} + AND ${tsExpr} >= fromUnixTimestamp64Milli({startMs:Int64}) + AND ${tsExpr} <= fromUnixTimestamp64Milli({endMs:Int64}) ORDER BY ${tsExpr} ASC LIMIT {n:UInt32} `; @@ -390,14 +525,15 @@ export function registerTraceWaterfall({ db: source.from.databaseName, tbl: source.from.tableName, tid: pickedTraceId, + startMs: fetchStart.getTime(), + endMs: fetchEnd.getTime(), n: input.maxSpans + 1, // +1 to detect truncation divisor, }, format: 'JSONEachRow', connectionId: source.connection.toString(), clickhouse_settings: { - readonly: '1', - // Per-query timeout matches the rest of the MCP for consistency. + ...MCP_CLICKHOUSE_SETTINGS, ...(source.querySettings ? Object.fromEntries( source.querySettings.map(s => [s.setting, s.value]), @@ -418,6 +554,25 @@ export function registerTraceWaterfall({ const spans = truncated ? rows.slice(0, input.maxSpans) : rows; if (spans.length === 0) { + // The window was often chosen by the probe, not the caller, so the hint + // must reflect what actually ran rather than tell the user to widen a + // window they never set. + let hint: string; + if (probeFailed) { + hint = + 'TraceId picked, but the timestamp probe failed (likely a query ' + + 'timeout) and no spans were found in the fallback window. Retry, ' + + 'or pass an explicit startTime/endTime around when the trace ran.'; + } else if (input.traceId && usedDefaultWindow) { + hint = + 'No spans found for this traceId within the last 90 days (the ' + + 'probe ceiling). If the trace is older, pass an explicit startTime ' + + '(ISO 8601) covering when it ran.'; + } else { + hint = + 'TraceId picked, but no spans exist in the time window. The trace ' + + 'may have spans outside startTime/endTime — widen the window.'; + } return { content: [ { @@ -426,7 +581,7 @@ export function registerTraceWaterfall({ { result: null, traceId: pickedTraceId, - hint: 'TraceId picked, but no spans exist in the time window. The trace may have spans outside startTime/endTime — widen the window.', + hint, }, null, 2, @@ -485,6 +640,7 @@ export function registerTraceWaterfall({ host: logConn.host, username: logConn.username, password: logConn.password, + requestTimeout: MCP_REQUEST_TIMEOUT, }); } } @@ -499,6 +655,8 @@ export function registerTraceWaterfall({ ${logSpanIdExpr} AS spanId FROM {db:Identifier}.{tbl:Identifier} WHERE ${logTraceIdExpr} = {tid:String} + AND ${logTsExpr} >= fromUnixTimestamp64Milli({startMs:Int64}) + AND ${logTsExpr} <= fromUnixTimestamp64Milli({endMs:Int64}) ORDER BY ${logTsExpr} ASC LIMIT {n:UInt32} `; @@ -509,12 +667,14 @@ export function registerTraceWaterfall({ db: logSource.from.databaseName, tbl: logSource.from.tableName, tid: pickedTraceId, + startMs: fetchStart.getTime(), + endMs: fetchEnd.getTime(), n: input.maxLogs + 1, // +1 to detect truncation }, format: 'JSONEachRow', connectionId: logSource.connection.toString(), clickhouse_settings: { - readonly: '1', + ...MCP_CLICKHOUSE_SETTINGS, ...(logSource.querySettings ? Object.fromEntries( logSource.querySettings.map(s => [s.setting, s.value]), From d670fccf9810f39b95ed82a41e3fe450e5022abc Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Fri, 11 Sep 2026 16:48:59 -0600 Subject: [PATCH 02/10] fix(mcp): address trace-waterfall review feedback - 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. --- .../api/src/mcp/__tests__/trace.int.test.ts | 5 ++ packages/api/src/mcp/tools/trace/waterfall.ts | 56 +++++++++++++++---- 2 files changed, 49 insertions(+), 12 deletions(-) diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index d3d1b7cab5..95f5343bc1 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -588,6 +588,9 @@ describe('MCP Trace Tools', () => { 'sentinel_old_span', ); expect(output.spans.filter((s: any) => s.depth === 0)).toHaveLength(1); + // The clamp dropped earlier spans, so the output must say so rather than + // silently promise the whole tree. + expect(output.windowNote).toContain('fetch-window cap'); }); }); @@ -653,6 +656,8 @@ describe('MCP Trace Tools', () => { expect(output.spans.filter((s: any) => s.depth === 0)).toHaveLength(1); // A fixed first-seen + 1h lead would have cut off this late child's log. expect(output.logsCount).toBe(1); + // An 85-min spread is under the fetch-window cap, so no clamp warning. + expect(output.windowNote).toBeUndefined(); }); }); diff --git a/packages/api/src/mcp/tools/trace/waterfall.ts b/packages/api/src/mcp/tools/trace/waterfall.ts index 9678d4b26c..301daaa264 100644 --- a/packages/api/src/mcp/tools/trace/waterfall.ts +++ b/packages/api/src/mcp/tools/trace/waterfall.ts @@ -113,8 +113,6 @@ const traceSchema = z.object({ type TraceInput = z.infer; -// ─── Safety limits ─────────────────────────────────────────────────────────── - // Probe-window tuning. The span/log fetch is time-bounded to the // trace's probed [min, max] extent so ClickHouse prunes partitions. The pads // absorb clock skew between emitters; they do NOT cover trace duration — the @@ -197,6 +195,8 @@ function parseProbeTimestamp(value: string | undefined): number | null { return isNaN(ms) || ms <= 0 ? null : ms; } +type ProbedWindow = { start: Date; end: Date; clamped: boolean }; + /** * Probe a trace's [min, max] span timestamps within [startDate, endDate] and * return a fetch window covering that extent (padded, then width-clamped). @@ -204,7 +204,10 @@ function parseProbeTimestamp(value: string | undefined): number | null { * and keeps a long trace from being truncated by a fixed lead. The probe is * time-bounded so it prunes partitions; the caller sets [startDate, endDate]. * - * Returns null when no span is found, so the caller falls back to its window. + * `clamped` is true when the trace's extent exceeded TRACE_MAX_FETCH_WINDOW_MS + * and the window was capped to the recent tail — the returned tree may then be + * missing early spans. Returns null when no span is found, so the caller falls + * back to its window. */ async function probeTraceWindow( clickhouseClient: ClickhouseClient, @@ -218,7 +221,7 @@ async function probeTraceWindow( startDate: Date; endDate: Date; }, -): Promise<[Date, Date] | null> { +): Promise { const probeQuery = ` SELECT min(${params.tsExpr}) AS firstSeen, @@ -254,11 +257,14 @@ async function probeTraceWindow( const fetchEnd = lastSeen + TRACE_PROBE_TRAIL_PAD_MS; // Anchor to the recent tail and clamp the width so a wide-spread/reused // TraceId can't balloon the fetch back toward the 90-day probe range. - const fetchStart = Math.max( - firstSeen - TRACE_PROBE_LEAD_PAD_MS, - fetchEnd - TRACE_MAX_FETCH_WINDOW_MS, - ); - return [new Date(fetchStart), new Date(fetchEnd)]; + const unclampedStart = firstSeen - TRACE_PROBE_LEAD_PAD_MS; + const clampFloor = fetchEnd - TRACE_MAX_FETCH_WINDOW_MS; + const fetchStart = Math.max(unclampedStart, clampFloor); + return { + start: new Date(fetchStart), + end: new Date(fetchEnd), + clamped: unclampedStart < clampFloor, + }; } // ─── Tool definition ───────────────────────────────────────────────────────── @@ -469,6 +475,7 @@ export function registerTraceWaterfall({ let fetchStart = startDate; let fetchEnd = endDate; let probeFailed = false; + let windowClamped = false; const usedDefaultWindow = input.startTime == null; if (usedDefaultWindow) { const probeStart = input.traceId @@ -486,7 +493,9 @@ export function registerTraceWaterfall({ endDate, }); if (probed) { - [fetchStart, fetchEnd] = probed; + fetchStart = probed.start; + fetchEnd = probed.end; + windowClamped = probed.clamped; } } catch { // probeTraceWindow returns null (not throws) for the empty case, so a @@ -532,13 +541,15 @@ export function registerTraceWaterfall({ }, format: 'JSONEachRow', connectionId: source.connection.toString(), + // MCP settings win over source.querySettings so a source can't relax + // the max_execution_time / readonly ceiling this tool depends on. clickhouse_settings: { - ...MCP_CLICKHOUSE_SETTINGS, ...(source.querySettings ? Object.fromEntries( source.querySettings.map(s => [s.setting, s.value]), ) : {}), + ...MCP_CLICKHOUSE_SETTINGS, }, }); rows = @@ -595,6 +606,24 @@ export function registerTraceWaterfall({ const root = tree.find(s => s.depth === 0) ?? tree[0]; const totalDuration = Math.max(...spans.map(s => s.durationMs)); + // When the extent probe failed we fell back to the default window, which + // may not cover the whole trace — so spans that came back could be a + // partial tree with a false root. Warn rather than present it as complete. + const probeNote = probeFailed + ? 'The span-extent probe failed (likely a query timeout), so the fetch ' + + 'used the default window and this tree may be incomplete. Retry, or ' + + 'pass an explicit startTime/endTime around when the trace ran.' + : undefined; + + // The fetch window is capped so a wide-spread trace can't scan the world; + // that cap can drop the earliest spans of a trace that ran longer than + // the cap. Say so rather than promising the whole tree. + const windowNote = windowClamped + ? 'This trace spans longer than the fetch-window cap, so the earliest ' + + 'spans may be missing. Pass an explicit startTime covering the ' + + "trace's start to see the full tree." + : undefined; + // ── Step 3: fetch correlated logs (when logSourceId is configured) ── type LogRow = { timestamp: string; @@ -673,13 +702,14 @@ export function registerTraceWaterfall({ }, format: 'JSONEachRow', connectionId: logSource.connection.toString(), + // MCP settings win over source.querySettings (see span fetch). clickhouse_settings: { - ...MCP_CLICKHOUSE_SETTINGS, ...(logSource.querySettings ? Object.fromEntries( logSource.querySettings.map(s => [s.setting, s.value]), ) : {}), + ...MCP_CLICKHOUSE_SETTINGS, }, }); const allLogs = @@ -721,6 +751,8 @@ export function registerTraceWaterfall({ } : {}), ...(logsNote ? { logsNote } : {}), + ...(probeNote ? { probeNote } : {}), + ...(windowNote ? { windowNote } : {}), ...(truncated ? { note: `Result truncated to ${input.maxSpans} spans. Increase maxSpans (max 2000) or narrow the trace if needed.`, From eb5b4127a024ea50abfa05fb759387dcd75bdbef Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Fri, 11 Sep 2026 17:16:44 -0600 Subject: [PATCH 03/10] fix(mcp): address deep-review findings on trace waterfall MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - 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. --- packages/api/src/mcp/__tests__/query.test.ts | 8 +++ .../api/src/mcp/__tests__/trace.int.test.ts | 50 ++++++++++++++++++- packages/api/src/mcp/tools/query/helpers.ts | 5 +- packages/api/src/mcp/tools/trace/waterfall.ts | 48 ++++++++++++------ 4 files changed, 93 insertions(+), 18 deletions(-) diff --git a/packages/api/src/mcp/__tests__/query.test.ts b/packages/api/src/mcp/__tests__/query.test.ts index 7befc707be..4c6f0b5ba7 100644 --- a/packages/api/src/mcp/__tests__/query.test.ts +++ b/packages/api/src/mcp/__tests__/query.test.ts @@ -318,6 +318,14 @@ describe('errorHint', () => { expect(hint).toContain('constraint'); }); + it('routes a max_execution_time constraint error to the constraint hint, not the timeout hint', () => { + const hint = errorHint( + "Setting max_execution_time shouldn't be greater than 10. (SETTING_CONSTRAINT_VIOLATION)", + ); + expect(hint).toContain('constraint'); + expect(hint).not.toContain('execution-time limit'); + }); + it('should return null for unrecognized errors', () => { const hint = errorHint('Connection refused'); expect(hint).toBeNull(); diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index 95f5343bc1..e982430994 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -598,7 +598,7 @@ describe('MCP Trace Tools', () => { // 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'; + const LONG_TRACE_ID = 'a1b2c3d4e5f60000111122223333long'; const LONG_SVC = 'wf-longtrace-svc'; const now = new Date(); // Root two days ago; a child span ~2h later. A fixed first-seen + 1h lead @@ -717,6 +717,54 @@ describe('MCP Trace Tools', () => { expect(output.spans.filter((s: any) => s.depth === 0)).toHaveLength(1); expect(output.rootSpan.spanId).toBe('pick_root_span01'); }); + + it('probes in auto-pick even with an explicit startTime (pick window, not a fetch bound)', async () => { + // Own trace + service so it's isolated from the sibling test (the + // traces table is not cleared between tests). startTime here is the + // pick window; the picked trace's root predates it, so the fetch must + // still probe the trace's real extent rather than honoring startTime. + const PICK2_TRACE_ID = 'cccc3333dddd4444eeee5555ffff6666'; + const PICK2_SVC = 'wf-autopick-window-svc'; + await bulkInsertTraces([ + { + Timestamp: rootTs, + TraceId: PICK2_TRACE_ID, + SpanId: 'pick2_root_span01', + ParentSpanId: '', + SpanName: 'GET /wf-autopick2/root', + SpanKind: 'SPAN_KIND_SERVER', + ServiceName: PICK2_SVC, + Duration: 2_400_000_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + { + Timestamp: childTs, + TraceId: PICK2_TRACE_ID, + SpanId: 'pick2_child_span1', + ParentSpanId: 'pick2_root_span01', + SpanName: 'wf-autopick2-child', + SpanKind: 'SPAN_KIND_CLIENT', + ServiceName: PICK2_SVC, + Duration: 100_000_000, + StatusCode: 'STATUS_CODE_OK', + }, + ]); + + const result = await callTool(client, 'clickstack_trace_waterfall', { + sourceId: traceSource._id.toString(), + pickFilter: `ServiceName:${PICK2_SVC}`, + pickBy: 'slowest', + includeLogs: false, + startTime: new Date(now.getTime() - 10 * 60 * 1000).toISOString(), + endTime: new Date(now.getTime() + 60 * 1000).toISOString(), + }); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + expect(output.traceId).toBe(PICK2_TRACE_ID); + expect(output.spanCount).toBe(2); + expect(output.rootSpan.spanId).toBe('pick2_root_span01'); + }); }); describe('first_error pick mode', () => { diff --git a/packages/api/src/mcp/tools/query/helpers.ts b/packages/api/src/mcp/tools/query/helpers.ts index b5b7eaa96e..3dcdcb0d52 100644 --- a/packages/api/src/mcp/tools/query/helpers.ts +++ b/packages/api/src/mcp/tools/query/helpers.ts @@ -908,7 +908,10 @@ export function errorHint(msg: string, error?: unknown): string | null { 'The result row count is too large to serialize back to the agent.' ); } - if (/TIMEOUT_EXCEEDED|Timeout exceeded|max_execution_time/i.test(msg)) { + // Match only real timeouts. A bare `max_execution_time` substring would also + // hijack SETTING_CONSTRAINT_VIOLATION / readonly errors ("Setting + // max_execution_time shouldn't be greater than…"), which need a different fix. + if (/TIMEOUT_EXCEEDED|Timeout exceeded/i.test(msg)) { return ( 'The query exceeded its execution-time limit. Narrow the time range so ' + 'ClickHouse can prune partitions, add filters to reduce the rows scanned, ' + diff --git a/packages/api/src/mcp/tools/trace/waterfall.ts b/packages/api/src/mcp/tools/trace/waterfall.ts index 301daaa264..047d9aa479 100644 --- a/packages/api/src/mcp/tools/trace/waterfall.ts +++ b/packages/api/src/mcp/tools/trace/waterfall.ts @@ -1,4 +1,5 @@ import { getMetadata } from '@hyperdx/common-utils/dist/core/metadata'; +import { getFirstTimestampValueExpression } from '@hyperdx/common-utils/dist/core/utils'; import { type BuilderChartConfigWithDateRange, type ChartConfigWithDateRange, @@ -360,6 +361,11 @@ export function registerTraceWaterfall({ const spanKindExpr = source.spanKindExpression; const durationExpr = source.durationExpression; const tsExpr = source.timestampValueExpression; + // A source's timestampValueExpression may be a comma-separated list (e.g. + // "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); const serviceNameExpr = source.serviceNameExpression ?? "''"; const statusCodeExpr = source.statusCodeExpression ?? "''"; const statusMessageExpr = source.statusMessageExpression ?? "''"; @@ -395,8 +401,8 @@ export function registerTraceWaterfall({ input.pickBy === 'slowest' ? `max(${durationExpr}) DESC` : input.pickBy === 'first_error' - ? `min(${tsExpr}) ASC` - : `max(${tsExpr}) DESC`; + ? `min(${tsExprFirst}) ASC` + : `max(${tsExprFirst}) DESC`; const pickConfig: BuilderChartConfigWithDateRange = { displayType: DisplayType.Table, @@ -468,26 +474,34 @@ export function registerTraceWaterfall({ } // The fetch must be time-bounded so ClickHouse prunes partitions, but the - // default 15-min window is too narrow: an explicit traceId may be older - // than it, and an auto-picked trace is only guaranteed one span inside it - // (its root/tail can lie outside, giving a partial tree). So when the - // window was defaulted, probe the trace's real [min, max] extent instead. + // [startDate, endDate] window is often too narrow to bound it safely: + // - an explicit traceId with the default window may be for an older + // trace outside it; + // - in auto-pick mode startTime is the *pick* window ("find a slow + // trace from the last hour"), not a fetch bound — the picked trace is + // only guaranteed one span inside it, so its root/tail can lie outside + // and the fetch would return a partial tree. + // Probe the trace's real [min, max] extent in both cases. The only time + // we honor the window verbatim is an explicit traceId WITH an explicit + // startTime, where the caller has deliberately set a fetch bound. let fetchStart = startDate; let fetchEnd = endDate; let probeFailed = false; let windowClamped = false; + const isAutoPick = input.traceId == null; const usedDefaultWindow = input.startTime == null; - if (usedDefaultWindow) { - const probeStart = input.traceId - ? new Date(endDate.getTime() - TRACE_PROBE_MAX_LOOKBACK_MS) - : new Date(startDate.getTime() - TRACE_PROBE_AUTOPICK_LOOKBACK_MS); + if (isAutoPick || usedDefaultWindow) { + const probeStart = + input.traceId && usedDefaultWindow + ? new Date(endDate.getTime() - TRACE_PROBE_MAX_LOOKBACK_MS) + : new Date(startDate.getTime() - TRACE_PROBE_AUTOPICK_LOOKBACK_MS); try { const probed = await probeTraceWindow(clickhouseClient, { databaseName: source.from.databaseName, tableName: source.from.tableName, connectionId: source.connection.toString(), traceIdExpr, - tsExpr, + tsExpr: tsExprFirst, traceId: pickedTraceId, startDate: probeStart, endDate, @@ -516,13 +530,13 @@ export function registerTraceWaterfall({ ${durationExpr} / {divisor:Float64} AS durationMs, ${statusCodeExpr} AS statusCode, ${statusMessageExpr} AS statusMessage, - ${tsExpr} AS timestamp, + ${tsExprFirst} AS timestamp, ${attrsExpr} AS spanAttributes FROM {db:Identifier}.{tbl:Identifier} WHERE ${traceIdExpr} = {tid:String} - AND ${tsExpr} >= fromUnixTimestamp64Milli({startMs:Int64}) - AND ${tsExpr} <= fromUnixTimestamp64Milli({endMs:Int64}) - ORDER BY ${tsExpr} ASC + AND ${tsExprFirst} >= fromUnixTimestamp64Milli({startMs:Int64}) + AND ${tsExprFirst} <= fromUnixTimestamp64Milli({endMs:Int64}) + ORDER BY ${tsExprFirst} ASC LIMIT {n:UInt32} `; @@ -647,7 +661,9 @@ export function registerTraceWaterfall({ } else { const logTraceIdExpr = logSource.traceIdExpression ?? 'TraceId'; const logSpanIdExpr = logSource.spanIdExpression ?? "''"; - const logTsExpr = logSource.timestampValueExpression; + const logTsExpr = getFirstTimestampValueExpression( + logSource.timestampValueExpression, + ); const logBodyExpr = logSource.bodyExpression ?? "''"; const logSevExpr = logSource.severityTextExpression ?? "''"; const logSvcExpr = logSource.serviceNameExpression ?? "''"; From 35e586c840f17aa59890be89493fb79734e520fe Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 12:35:06 -0600 Subject: [PATCH 04/10] fix(mcp): time-limit the trace top-operations tool and explain timeouts clickstack_trace_top_time_consuming_operations built its ClickHouse client with the 1h default request timeout and set no max_execution_time, so on self-hosted it could run for an hour; on ClickHouse Cloud a third of calls ended in a bare "Timeout error.". - Use MCP_REQUEST_TIMEOUT and MCP_CLICKHOUSE_SETTINGS like the other MCP query tools. MCP settings override source.querySettings so a source can't lift the time limit or the readonly guard. - On timeout, tell the agent to shorten the window, scope the filter or set minParentDurationMs instead of saying the SQL is invalid. - Recognise the client-side "Timeout error." in errorHint. - Use the first timestamp expression so multi-column sources build valid SQL. Co-Authored-By: Claude Opus 5.5 (1M context) --- packages/api/src/mcp/__tests__/query.test.ts | 38 +++++++++ .../api/src/mcp/__tests__/trace.int.test.ts | 78 +++++++++++++++++++ packages/api/src/mcp/tools/query/helpers.ts | 23 +++++- packages/api/src/mcp/tools/trace/breakdown.ts | 34 ++++++-- 4 files changed, 164 insertions(+), 9 deletions(-) diff --git a/packages/api/src/mcp/__tests__/query.test.ts b/packages/api/src/mcp/__tests__/query.test.ts index 4c6f0b5ba7..877ebd1321 100644 --- a/packages/api/src/mcp/__tests__/query.test.ts +++ b/packages/api/src/mcp/__tests__/query.test.ts @@ -19,6 +19,7 @@ import { errorHint, getClickHouseErrorType, INCREASE_TOP_N_CAP, + isQueryTimeoutError, isServerError, mergeWhereIntoSelectItems, parseTimeRange, @@ -309,6 +310,11 @@ describe('errorHint', () => { expect(hint).toContain('Narrow the time range'); }); + it('should match the client-side request timeout', () => { + const hint = errorHint('Timeout error.'); + expect(hint).toContain('execution-time limit'); + }); + it('should match SETTING_CONSTRAINT_VIOLATION errors', () => { const hint = errorHint( "Setting max_result_rows shouldn't be greater than 1000. (SETTING_CONSTRAINT_VIOLATION)", @@ -332,6 +338,38 @@ describe('errorHint', () => { }); }); +describe('isQueryTimeoutError', () => { + it.each([ + ['client request timeout', new Error('Timeout error.')], + [ + 'server TIMEOUT_EXCEEDED', + new Error('Code: 159. Timeout exceeded: elapsed 30s (TIMEOUT_EXCEEDED)'), + ], + [ + 'timeout in the cause chain', + new Error('', { cause: new Error('Timeout error.') }), + ], + ])('matches a %s', (_label, error) => { + expect(isQueryTimeoutError(error)).toBe(true); + }); + + it.each([ + [ + 'max_execution_time constraint violation', + new Error( + "Setting max_execution_time shouldn't be greater than 10. (SETTING_CONSTRAINT_VIOLATION)", + ), + ], + [ + 'socket timeout text inside a longer message', + new Error('Timeout error. retrying'), + ], + ['non-Error value', 'Timeout error.'], + ])('does not match a %s', (_label, error) => { + expect(isQueryTimeoutError(error)).toBe(false); + }); +}); + // ─── getClickHouseErrorType ────────────────────────────────────────────────── describe('getClickHouseErrorType', () => { diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index e982430994..bd24f8b569 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -1,6 +1,7 @@ import { SourceKind } from '@hyperdx/common-utils/dist/types'; import { Client } from '@modelcontextprotocol/sdk/client/index.js'; +import { ClickhouseClient } from '@/clickhouse'; import * as config from '@/config'; import { bulkInsertData, @@ -10,6 +11,7 @@ import { getLoggedInAgent, getServer, } from '@/fixtures'; +import { MCP_REQUEST_TIMEOUT } from '@/mcp/tools/query/helpers'; import { McpContext } from '@/mcp/tools/types'; import Connection from '@/models/connection'; import { Source, type SourceDocument } from '@/models/source'; @@ -1207,6 +1209,82 @@ describe('MCP Trace Tools', () => { expect(result.isError).toBe(true); expect(getFirstText(result)).toContain('Failed to compute breakdown'); }); + + it('applies the MCP time limits even when the source sets max_execution_time', async () => { + await Source.updateOne( + { _id: traceSource._id }, + { + querySettings: [ + { setting: 'max_execution_time', value: '3600' }, + { setting: 'max_threads', value: '2' }, + ], + }, + ); + const querySpy = jest.spyOn(ClickhouseClient.prototype, 'query'); + try { + const result = await callTool( + client, + 'clickstack_trace_top_time_consuming_operations', + { + sourceId: traceSource._id.toString(), + parentFilter: `ServiceName = '${PARENT_SVC}' AND SpanName = '${PARENT_OP}'`, + startTime: new Date(now.getTime() - 10 * 60 * 1000).toISOString(), + endTime: new Date(now.getTime() + 60 * 1000).toISOString(), + }, + ); + + expect(result.isError).toBeFalsy(); + const call = querySpy.mock.calls.find(([args]) => + args.query.includes('parent_traces'), + ); + expect(call?.[0].clickhouse_settings).toMatchObject({ + max_execution_time: 30, + readonly: '2', + max_threads: '2', + }); + const ctx: ClickhouseClient = + querySpy.mock.contexts[querySpy.mock.calls.indexOf(call!)]; + expect(ctx.requestTimeoutMs).toBe(MCP_REQUEST_TIMEOUT); + } finally { + querySpy.mockRestore(); + } + }); + + it.each([ + ['client request timeout', new Error('Timeout error.')], + [ + 'ClickHouse TIMEOUT_EXCEEDED', + new Error( + 'Code: 159. DB::Exception: Timeout exceeded: elapsed 30.001 seconds, maximum: 30. (TIMEOUT_EXCEEDED)', + ), + ], + ])('returns actionable guidance on a %s', async (_label, error) => { + const querySpy = jest + .spyOn(ClickhouseClient.prototype, 'query') + .mockRejectedValue(error); + try { + const result = await callTool( + client, + 'clickstack_trace_top_time_consuming_operations', + { + sourceId: traceSource._id.toString(), + parentFilter: `ServiceName = '${PARENT_SVC}' AND SpanName = '${PARENT_OP}'`, + startTime: new Date(now.getTime() - 10 * 60 * 1000).toISOString(), + endTime: new Date(now.getTime() + 60 * 1000).toISOString(), + }, + ); + + expect(result.isError).toBe(true); + const text = getFirstText(result); + expect(text).toContain('Failed to compute breakdown'); + expect(text).toContain('execution-time limit'); + expect(text).toContain('shorter startTime/endTime window'); + expect(text).toContain('minParentDurationMs'); + expect(text).not.toContain('must be valid ClickHouse SQL'); + } finally { + querySpy.mockRestore(); + } + }); }); }); }); diff --git a/packages/api/src/mcp/tools/query/helpers.ts b/packages/api/src/mcp/tools/query/helpers.ts index 3dcdcb0d52..d69facf35d 100644 --- a/packages/api/src/mcp/tools/query/helpers.ts +++ b/packages/api/src/mcp/tools/query/helpers.ts @@ -869,6 +869,24 @@ function findCause( return undefined; } +// Match only real timeouts. A bare `max_execution_time` substring would also +// hijack SETTING_CONSTRAINT_VIOLATION / readonly errors ("Setting +// max_execution_time shouldn't be greater than…"), which need a different fix. +// "Timeout error." is what @clickhouse/client throws when the HTTP request +// timeout fires before ClickHouse answers. +const QUERY_TIMEOUT_RE = + /TIMEOUT_EXCEEDED|Timeout exceeded|^Timeout error\.?$/i; + +/** True when a query failed because it ran out of time, server- or client-side. */ +export function isQueryTimeoutError(e: unknown): boolean { + let current: unknown = e; + for (let i = 0; i <= 5 && current instanceof Error; i++) { + if (QUERY_TIMEOUT_RE.test(current.message)) return true; + current = current.cause; + } + return false; +} + /** @internal Exported for testing only. */ export function errorHint(msg: string, error?: unknown): string | null { const unknownVariableError = findCause( @@ -908,10 +926,7 @@ export function errorHint(msg: string, error?: unknown): string | null { 'The result row count is too large to serialize back to the agent.' ); } - // Match only real timeouts. A bare `max_execution_time` substring would also - // hijack SETTING_CONSTRAINT_VIOLATION / readonly errors ("Setting - // max_execution_time shouldn't be greater than…"), which need a different fix. - if (/TIMEOUT_EXCEEDED|Timeout exceeded/i.test(msg)) { + if (QUERY_TIMEOUT_RE.test(msg)) { return ( 'The query exceeded its execution-time limit. Narrow the time range so ' + 'ClickHouse can prune partitions, add filters to reduce the rows scanned, ' + diff --git a/packages/api/src/mcp/tools/trace/breakdown.ts b/packages/api/src/mcp/tools/trace/breakdown.ts index a0c6fc9e57..e5f16d4033 100644 --- a/packages/api/src/mcp/tools/trace/breakdown.ts +++ b/packages/api/src/mcp/tools/trace/breakdown.ts @@ -15,6 +15,7 @@ * endpoint" without dropping into raw SQL with self-JOINs. The builder * tools (table / timeseries / search) can't express the TraceId subselect. */ +import { getFirstTimestampValueExpression } from '@hyperdx/common-utils/dist/core/utils'; import { SourceKind } from '@hyperdx/common-utils/dist/types'; import { z } from 'zod'; @@ -23,6 +24,9 @@ import { getConnectionById } from '@/controllers/connection'; import { getSource } from '@/controllers/sources'; import { clickHouseErrorResult, + isQueryTimeoutError, + MCP_CLICKHOUSE_SETTINGS, + MCP_REQUEST_TIMEOUT, parseTimeRange, } from '@/mcp/tools/query/helpers'; import type { ToolRegistrar } from '@/mcp/tools/types'; @@ -99,6 +103,20 @@ function durationDivisor(precision: number): number { return Math.pow(10, Math.max(0, precision - 3)); } +// The child stage looks spans up by TraceId, which is not in the sort key, so +// it reads every span in the window regardless of how few parents matched. +// Cost tracks the window length, so that is the first thing to shrink. +const TIMEOUT_SUFFIX = + 'This tool reads every span in the time window to find the children of ' + + 'matching traces, so cost grows with the window length. Retry with a ' + + 'shorter startTime/endTime window (e.g. 15-60 minutes around the ' + + 'incident), scope parentFilter to one ServiceName AND SpanName, set ' + + 'minParentDurationMs to break down only slow parents, or lower ' + + 'maxParentTraces.'; + +const INVALID_FILTER_SUFFIX = + "The parentFilter must be valid ClickHouse SQL referencing columns on the trace table (e.g. ServiceName = 'X' AND SpanName = 'Y')."; + export function registerTraceBreakdown({ context, registerTool, @@ -192,7 +210,9 @@ export function registerTraceBreakdown({ // Source-configured SQL expressions. These are trusted (set by the // team admin in source config) and we substitute them into the // generated SQL. - const tsExpr = source.timestampValueExpression; + const tsExpr = getFirstTimestampValueExpression( + source.timestampValueExpression, + ); const traceIdExpr = source.traceIdExpression; const spanNameExpr = source.spanNameExpression ?? "''"; const serviceNameExpr = source.serviceNameExpression ?? "''"; @@ -260,6 +280,7 @@ LIMIT {topN:UInt32} host: connection.host, username: connection.username, password: connection.password, + requestTimeout: MCP_REQUEST_TIMEOUT, }); type Row = { @@ -279,14 +300,16 @@ LIMIT {topN:UInt32} query_params: params, format: 'JSON', connectionId: source.connection.toString(), + // MCP settings win over source.querySettings so a source can't relax + // the max_execution_time ceiling, or the readonly guard that blocks + // DDL/DML injected through parentFilter. clickhouse_settings: { - // Prevent DDL/DML injection via parentFilter — only SELECTs allowed. - readonly: '1', ...(source.querySettings ? Object.fromEntries( source.querySettings.map(s => [s.setting, s.value]), ) : {}), + ...MCP_CLICKHOUSE_SETTINGS, }, }); const json = (await ( @@ -296,8 +319,9 @@ LIMIT {topN:UInt32} } catch (e) { return clickHouseErrorResult(e, { prefix: 'Failed to compute breakdown', - suffix: - "The parentFilter must be valid ClickHouse SQL referencing columns on the trace table (e.g. ServiceName = 'X' AND SpanName = 'Y').", + suffix: isQueryTimeoutError(e) + ? TIMEOUT_SUFFIX + : INVALID_FILTER_SUFFIX, }); } From 18591b89aa0167139792182f0421386645923c5d Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 13:48:42 -0600 Subject: [PATCH 05/10] fix(mcp): filter breakdown time on every timestamp column; add changeset Date-first multi-column timestampValueExpression (e.g. EventDate, EventTime) compared a Date against millisecond bounds and dropped every span after midnight. Render the time filters with timeFilterExpr (greptile P1), cover the multi-column path with an integration test (deep-review P2), and add the missing changeset. --- .changeset/trace-breakdown-timeout.md | 12 ++++ .../api/src/mcp/__tests__/trace.int.test.ts | 25 +++++++ packages/api/src/mcp/tools/trace/breakdown.ts | 71 +++++++++++++------ 3 files changed, 86 insertions(+), 22 deletions(-) create mode 100644 .changeset/trace-breakdown-timeout.md diff --git a/.changeset/trace-breakdown-timeout.md b/.changeset/trace-breakdown-timeout.md new file mode 100644 index 0000000000..26c435b3f9 --- /dev/null +++ b/.changeset/trace-breakdown-timeout.md @@ -0,0 +1,12 @@ +--- +'@hyperdx/api': patch +--- + +fix(mcp): time-limit the `clickstack_trace_top_time_consuming_operations` tool. +Its queries now use the MCP request timeout and `max_execution_time` ceiling, +which a source's `querySettings` can no longer override. A timeout returns +guidance to shorten the window or narrow `parentFilter` instead of an "invalid +SQL" hint, and the client-side `Timeout error.` now gets the timeout hint in +every MCP tool. Sources with a multi-column `timestampValueExpression` +(including a leading Date column such as `EventDate, EventTime`) now return +correct breakdowns. diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index bd24f8b569..40715f7fc7 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -1194,6 +1194,31 @@ describe('MCP Trace Tools', () => { expect(output.summary.grandTotalTimeMs).toBeGreaterThan(0); }); + it('handles a multi-column timestampValueExpression with a leading Date column', async () => { + await Source.updateOne( + { _id: traceSource._id }, + { timestampValueExpression: 'toDate(Timestamp), Timestamp' }, + ); + + const result = await callTool( + client, + 'clickstack_trace_top_time_consuming_operations', + { + sourceId: traceSource._id.toString(), + parentFilter: `ServiceName = '${PARENT_SVC}' AND SpanName = '${PARENT_OP}'`, + startTime: new Date(now.getTime() - 10 * 60 * 1000).toISOString(), + endTime: new Date(now.getTime() + 60 * 1000).toISOString(), + }, + ); + + expect(result.isError).toBeFalsy(); + const output = JSON.parse(getFirstText(result)); + const dbOp = output.operations.find( + (op: any) => op.operation === CHILD_DB_OP, + ); + expect(dbOp?.inParents).toBe(2); + }); + it('should return error for invalid parentFilter SQL', async () => { const result = await callTool( client, diff --git a/packages/api/src/mcp/tools/trace/breakdown.ts b/packages/api/src/mcp/tools/trace/breakdown.ts index e5f16d4033..1df7e6ffa5 100644 --- a/packages/api/src/mcp/tools/trace/breakdown.ts +++ b/packages/api/src/mcp/tools/trace/breakdown.ts @@ -15,7 +15,9 @@ * endpoint" without dropping into raw SQL with self-JOINs. The builder * tools (table / timeseries / search) can't express the TraceId subselect. */ -import { getFirstTimestampValueExpression } from '@hyperdx/common-utils/dist/core/utils'; +import type { ChSql } from '@hyperdx/common-utils/dist/clickhouse'; +import { getMetadata } from '@hyperdx/common-utils/dist/core/metadata'; +import { timeFilterExpr } from '@hyperdx/common-utils/dist/core/renderChartConfig'; import { SourceKind } from '@hyperdx/common-utils/dist/types'; import { z } from 'zod'; @@ -207,12 +209,51 @@ export function registerTraceBreakdown({ ); } + const clickhouseClient = new ClickhouseClient({ + host: connection.host, + username: connection.username, + password: connection.password, + requestTimeout: MCP_REQUEST_TIMEOUT, + }); + + // timeFilterExpr filters on every column of a multi-column + // timestampValueExpression and compares Date columns at day precision. + // Comparing a leading Date column (e.g. "EventDate, EventTime") against + // millisecond bounds would drop every span after midnight. + const renderTimeFilter = (start: number, end: number) => + timeFilterExpr({ + connectionId: source.connection.toString(), + databaseName: source.from.databaseName, + tableName: source.from.tableName, + timestampValueExpression: source.timestampValueExpression, + dateRange: [new Date(start), new Date(end)], + dateRangeStartInclusive: true, + dateRangeEndInclusive: true, + metadata: getMetadata(clickhouseClient), + }); + let parentTimeFilter: ChSql; + let childTimeFilter: ChSql; + try { + [parentTimeFilter, childTimeFilter] = await Promise.all([ + renderTimeFilter(startDate.getTime(), endDate.getTime()), + // Widen the child window by 60s on each side to catch children + // that started slightly before / ended slightly after the parent + // sampling window. + renderTimeFilter( + startDate.getTime() - 60_000, + endDate.getTime() + 60_000, + ), + ]); + } catch (e) { + return clickHouseErrorResult(e, { + prefix: 'Failed to compute breakdown', + suffix: isQueryTimeoutError(e) ? TIMEOUT_SUFFIX : undefined, + }); + } + // Source-configured SQL expressions. These are trusted (set by the // team admin in source config) and we substitute them into the // generated SQL. - const tsExpr = getFirstTimestampValueExpression( - source.timestampValueExpression, - ); const traceIdExpr = source.traceIdExpression; const spanNameExpr = source.spanNameExpression ?? "''"; const serviceNameExpr = source.serviceNameExpression ?? "''"; @@ -235,8 +276,7 @@ export function registerTraceBreakdown({ WITH parent_traces AS ( SELECT DISTINCT ${traceIdExpr} AS _trace_id FROM \`${dbName}\`.\`${tableName}\` - WHERE ${tsExpr} >= fromUnixTimestamp64Milli({startMs:Int64}) - AND ${tsExpr} <= fromUnixTimestamp64Milli({endMs:Int64}) + WHERE ${parentTimeFilter.sql} AND (${input.parentFilter}) ${minDurationClause} LIMIT {maxParentTraces:UInt32} @@ -251,8 +291,7 @@ SELECT quantile(0.99)(${durationExpr}) / {divisor:Float64} AS p99_ms FROM \`${dbName}\`.\`${tableName}\` WHERE ${traceIdExpr} IN (SELECT _trace_id FROM parent_traces) - AND ${tsExpr} >= fromUnixTimestamp64Milli({wideStartMs:Int64}) - AND ${tsExpr} <= fromUnixTimestamp64Milli({wideEndMs:Int64}) + AND ${childTimeFilter.sql} AND NOT (${input.parentFilter}) GROUP BY service, operation ORDER BY total_time_ms DESC @@ -260,13 +299,8 @@ LIMIT {topN:UInt32} `; const params: Record = { - startMs: startDate.getTime(), - endMs: endDate.getTime(), - // Widen the child window by 60s on each side to catch children - // that started slightly before / ended slightly after the parent - // sampling window. - wideStartMs: startDate.getTime() - 60_000, - wideEndMs: endDate.getTime() + 60_000, + ...parentTimeFilter.params, + ...childTimeFilter.params, maxParentTraces: input.maxParentTraces, topN: input.topN, divisor, @@ -276,13 +310,6 @@ LIMIT {topN:UInt32} params.minParentDurationStored = input.minParentDurationMs * divisor; } - const clickhouseClient = new ClickhouseClient({ - host: connection.host, - username: connection.username, - password: connection.password, - requestTimeout: MCP_REQUEST_TIMEOUT, - }); - type Row = { service: string; operation: string; From 84c9115fbf653f19d5e3a4abaae45f6155b3e43b Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 15:41:40 -0600 Subject: [PATCH 06/10] test(mcp): assert invalid-filter vs timeout suffix on breakdown errors (deep-review P3) --- packages/api/src/mcp/__tests__/trace.int.test.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index 40715f7fc7..fa4e11eeca 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -1232,7 +1232,10 @@ describe('MCP Trace Tools', () => { ); expect(result.isError).toBe(true); - expect(getFirstText(result)).toContain('Failed to compute breakdown'); + const text = getFirstText(result); + expect(text).toContain('Failed to compute breakdown'); + expect(text).toContain('must be valid ClickHouse SQL'); + expect(text).not.toContain('shorter startTime/endTime window'); }); it('applies the MCP time limits even when the source sets max_execution_time', async () => { From 4c8eccbaea8926e54d489bf19ce213726757bacc Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 15:56:01 -0600 Subject: [PATCH 07/10] chore: trigger CI after retargeting to main From 894e781f9173d15f0ac179693b932cb07e60817b Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 16:42:18 -0600 Subject: [PATCH 08/10] refactor(mcp): reuse checkAlerts isQueryTimeoutError in trace breakdown Drops the duplicate regex-based helper. The existing one also catches socket ETIMEDOUT, aborts, and ClickHouseError code 159, so those no longer get the invalid-SQL suffix (inline review minor). --- packages/api/src/mcp/__tests__/query.test.ts | 33 ------------------- .../api/src/mcp/__tests__/trace.int.test.ts | 9 +++-- packages/api/src/mcp/tools/query/helpers.ts | 10 ------ packages/api/src/mcp/tools/trace/breakdown.ts | 2 +- 4 files changed, 7 insertions(+), 47 deletions(-) diff --git a/packages/api/src/mcp/__tests__/query.test.ts b/packages/api/src/mcp/__tests__/query.test.ts index 877ebd1321..55b61d0af3 100644 --- a/packages/api/src/mcp/__tests__/query.test.ts +++ b/packages/api/src/mcp/__tests__/query.test.ts @@ -19,7 +19,6 @@ import { errorHint, getClickHouseErrorType, INCREASE_TOP_N_CAP, - isQueryTimeoutError, isServerError, mergeWhereIntoSelectItems, parseTimeRange, @@ -338,38 +337,6 @@ describe('errorHint', () => { }); }); -describe('isQueryTimeoutError', () => { - it.each([ - ['client request timeout', new Error('Timeout error.')], - [ - 'server TIMEOUT_EXCEEDED', - new Error('Code: 159. Timeout exceeded: elapsed 30s (TIMEOUT_EXCEEDED)'), - ], - [ - 'timeout in the cause chain', - new Error('', { cause: new Error('Timeout error.') }), - ], - ])('matches a %s', (_label, error) => { - expect(isQueryTimeoutError(error)).toBe(true); - }); - - it.each([ - [ - 'max_execution_time constraint violation', - new Error( - "Setting max_execution_time shouldn't be greater than 10. (SETTING_CONSTRAINT_VIOLATION)", - ), - ], - [ - 'socket timeout text inside a longer message', - new Error('Timeout error. retrying'), - ], - ['non-Error value', 'Timeout error.'], - ])('does not match a %s', (_label, error) => { - expect(isQueryTimeoutError(error)).toBe(false); - }); -}); - // ─── getClickHouseErrorType ────────────────────────────────────────────────── describe('getClickHouseErrorType', () => { diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index e6359681b1..5c42340043 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -1,3 +1,4 @@ +import { ClickHouseError } from '@clickhouse/client-common'; import { SourceKind } from '@hyperdx/common-utils/dist/types'; import { Client } from '@modelcontextprotocol/sdk/client/index.js'; @@ -1390,9 +1391,11 @@ describe('MCP Trace Tools', () => { ['client request timeout', new Error('Timeout error.')], [ 'ClickHouse TIMEOUT_EXCEEDED', - new Error( - 'Code: 159. DB::Exception: Timeout exceeded: elapsed 30.001 seconds, maximum: 30. (TIMEOUT_EXCEEDED)', - ), + new ClickHouseError({ + code: '159', + type: 'TIMEOUT_EXCEEDED', + message: 'Timeout exceeded: elapsed 30.001 seconds, maximum: 30', + }), ], ])('returns actionable guidance on a %s', async (_label, error) => { const querySpy = jest diff --git a/packages/api/src/mcp/tools/query/helpers.ts b/packages/api/src/mcp/tools/query/helpers.ts index d69facf35d..92ee856f26 100644 --- a/packages/api/src/mcp/tools/query/helpers.ts +++ b/packages/api/src/mcp/tools/query/helpers.ts @@ -877,16 +877,6 @@ function findCause( const QUERY_TIMEOUT_RE = /TIMEOUT_EXCEEDED|Timeout exceeded|^Timeout error\.?$/i; -/** True when a query failed because it ran out of time, server- or client-side. */ -export function isQueryTimeoutError(e: unknown): boolean { - let current: unknown = e; - for (let i = 0; i <= 5 && current instanceof Error; i++) { - if (QUERY_TIMEOUT_RE.test(current.message)) return true; - current = current.cause; - } - return false; -} - /** @internal Exported for testing only. */ export function errorHint(msg: string, error?: unknown): string | null { const unknownVariableError = findCause( diff --git a/packages/api/src/mcp/tools/trace/breakdown.ts b/packages/api/src/mcp/tools/trace/breakdown.ts index 1df7e6ffa5..0821a98f1c 100644 --- a/packages/api/src/mcp/tools/trace/breakdown.ts +++ b/packages/api/src/mcp/tools/trace/breakdown.ts @@ -26,13 +26,13 @@ import { getConnectionById } from '@/controllers/connection'; import { getSource } from '@/controllers/sources'; import { clickHouseErrorResult, - isQueryTimeoutError, MCP_CLICKHOUSE_SETTINGS, MCP_REQUEST_TIMEOUT, parseTimeRange, } from '@/mcp/tools/query/helpers'; import type { ToolRegistrar } from '@/mcp/tools/types'; import { mcpUserError } from '@/mcp/utils/errors'; +import { isQueryTimeoutError } from '@/tasks/checkAlerts/errors'; // ─── Schema ────────────────────────────────────────────────────────────────── From 3f3dde30e8c5c32e0e859e6d0ae9a91fe7327155 Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 17:04:44 -0600 Subject: [PATCH 09/10] refactor(mcp): share trace tool helpers and split breakdown schema - Move getMcpClickhouseClient, mcpQuerySettings, durationDivisor and the inclusive timeFilterExpr wrapper into trace/shared.ts; waterfall and breakdown both use them, so the MCP-settings-last order lives in one place. - Move the breakdown schema and tool description to breakdownSchema.ts (breakdown.ts 400 -> 266 lines). - errorHint also checks isQueryTimeoutError on the error object, so socket timeouts and aborts get the execution-time hint. - Type breakdown operations in tests instead of any. --- packages/api/src/mcp/__tests__/query.test.ts | 6 + .../api/src/mcp/__tests__/trace.int.test.ts | 17 +- packages/api/src/mcp/tools/query/helpers.ts | 3 +- packages/api/src/mcp/tools/trace/breakdown.ts | 180 +++--------------- .../src/mcp/tools/trace/breakdownSchema.ts | 110 +++++++++++ packages/api/src/mcp/tools/trace/shared.ts | 68 +++++++ packages/api/src/mcp/tools/trace/waterfall.ts | 67 ++----- 7 files changed, 235 insertions(+), 216 deletions(-) create mode 100644 packages/api/src/mcp/tools/trace/breakdownSchema.ts create mode 100644 packages/api/src/mcp/tools/trace/shared.ts diff --git a/packages/api/src/mcp/__tests__/query.test.ts b/packages/api/src/mcp/__tests__/query.test.ts index 55b61d0af3..ec6a52dd5b 100644 --- a/packages/api/src/mcp/__tests__/query.test.ts +++ b/packages/api/src/mcp/__tests__/query.test.ts @@ -314,6 +314,12 @@ describe('errorHint', () => { expect(hint).toContain('execution-time limit'); }); + it('should match a socket timeout from the error object', () => { + const error: NodeJS.ErrnoException = new Error('connect ETIMEDOUT'); + error.code = 'ETIMEDOUT'; + expect(errorHint(error.message, error)).toContain('execution-time limit'); + }); + it('should match SETTING_CONSTRAINT_VIOLATION errors', () => { const hint = errorHint( "Setting max_result_rows shouldn't be greater than 1000. (SETTING_CONSTRAINT_VIOLATION)", diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index 5c42340043..61f2737521 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -21,6 +21,15 @@ import { callTool, createTestClient, getFirstText } from './mcpTestUtils'; // ─── Helpers ────────────────────────────────────────────────────────────────── +type BreakdownOperation = { + service: string; + operation: string; + totalTimeMs: number; + calls: number; + inParents: number; + shareOfTotalTime: number; +}; + /** Insert trace spans into the default otel_traces table. */ async function bulkInsertTraces( spans: { @@ -1214,10 +1223,10 @@ describe('MCP Trace Tools', () => { // DB operations should be ranked first (higher total time) const dbOp = output.operations.find( - (op: any) => op.operation === CHILD_DB_OP, + (op: BreakdownOperation) => op.operation === CHILD_DB_OP, ); const cacheOp = output.operations.find( - (op: any) => op.operation === CHILD_CACHE_OP, + (op: BreakdownOperation) => op.operation === CHILD_CACHE_OP, ); expect(dbOp).toBeDefined(); expect(cacheOp).toBeDefined(); @@ -1252,7 +1261,7 @@ describe('MCP Trace Tools', () => { // Only trace 2's children should be included (1 call each) const dbOp = output.operations.find( - (op: any) => op.operation === CHILD_DB_OP, + (op: BreakdownOperation) => op.operation === CHILD_DB_OP, ); expect(dbOp).toBeDefined(); expect(dbOp.inParents).toBe(1); @@ -1323,7 +1332,7 @@ describe('MCP Trace Tools', () => { expect(result.isError).toBeFalsy(); const output = JSON.parse(getFirstText(result)); const dbOp = output.operations.find( - (op: any) => op.operation === CHILD_DB_OP, + (op: BreakdownOperation) => op.operation === CHILD_DB_OP, ); expect(dbOp?.inParents).toBe(2); }); diff --git a/packages/api/src/mcp/tools/query/helpers.ts b/packages/api/src/mcp/tools/query/helpers.ts index 92ee856f26..418e4364e1 100644 --- a/packages/api/src/mcp/tools/query/helpers.ts +++ b/packages/api/src/mcp/tools/query/helpers.ts @@ -32,6 +32,7 @@ import { convertToInternalTileConfig, isConfigTile, } from '@/routers/external-api/v2/utils/dashboards'; +import { isQueryTimeoutError } from '@/tasks/checkAlerts/errors'; import { trimToolResponse } from '@/utils/trimToolResponse'; import type { ExternalDashboardTileWithId } from '@/utils/zod'; import { externalDashboardTileSchemaWithId } from '@/utils/zod'; @@ -916,7 +917,7 @@ export function errorHint(msg: string, error?: unknown): string | null { 'The result row count is too large to serialize back to the agent.' ); } - if (QUERY_TIMEOUT_RE.test(msg)) { + if (QUERY_TIMEOUT_RE.test(msg) || isQueryTimeoutError(error)) { return ( 'The query exceeded its execution-time limit. Narrow the time range so ' + 'ClickHouse can prune partitions, add filters to reduce the rows scanned, ' + diff --git a/packages/api/src/mcp/tools/trace/breakdown.ts b/packages/api/src/mcp/tools/trace/breakdown.ts index 0821a98f1c..7cd7201d19 100644 --- a/packages/api/src/mcp/tools/trace/breakdown.ts +++ b/packages/api/src/mcp/tools/trace/breakdown.ts @@ -17,94 +17,28 @@ */ import type { ChSql } from '@hyperdx/common-utils/dist/clickhouse'; import { getMetadata } from '@hyperdx/common-utils/dist/core/metadata'; -import { timeFilterExpr } from '@hyperdx/common-utils/dist/core/renderChartConfig'; import { SourceKind } from '@hyperdx/common-utils/dist/types'; -import { z } from 'zod'; -import { ClickhouseClient } from '@/clickhouse'; -import { getConnectionById } from '@/controllers/connection'; import { getSource } from '@/controllers/sources'; import { clickHouseErrorResult, - MCP_CLICKHOUSE_SETTINGS, - MCP_REQUEST_TIMEOUT, parseTimeRange, } from '@/mcp/tools/query/helpers'; +import { + TRACE_BREAKDOWN_DESCRIPTION, + type TraceBreakdownInput, + traceBreakdownSchema, +} from '@/mcp/tools/trace/breakdownSchema'; +import { + durationDivisor, + getMcpClickhouseClient, + inclusiveTimeFilter, + mcpQuerySettings, +} from '@/mcp/tools/trace/shared'; import type { ToolRegistrar } from '@/mcp/tools/types'; import { mcpUserError } from '@/mcp/utils/errors'; import { isQueryTimeoutError } from '@/tasks/checkAlerts/errors'; -// ─── Schema ────────────────────────────────────────────────────────────────── - -const traceBreakdownSchema = z.object({ - sourceId: z - .string() - .describe( - 'Trace source ID. Must be a source of kind="trace". ' + - 'Call clickstack_list_sources to find available sources.', - ), - parentFilter: z - .string() - .max(4096) - .describe( - 'SQL WHERE clause that selects the PARENT spans you want to break ' + - 'down. The tool finds the distinct TraceIds matching this filter, ' + - 'then aggregates all spans within those traces. ' + - 'Use SQL syntax (not Lucene). Example: ' + - "\"ServiceName = '' AND SpanName = ''\".\n\n" + - 'SCOPE TO A SPECIFIC OPERATION, not just a service. A service-only ' + - 'filter mixes every endpoint together and returns whatever has the ' + - "loudest child-time across all parents, which usually isn't what " + - 'you want. Always include a SpanName (or another operation-level ' + - 'discriminator). To compare two slow operations, call this tool ' + - 'once per operation and diff the results — two operations with ' + - "similar p99 don't necessarily share a slow child.", - ), - startTime: z - .string() - .describe('Start of the parent-filter time window as ISO 8601. REQUIRED.'), - endTime: z - .string() - .describe('End of the parent-filter time window as ISO 8601. REQUIRED.'), - minParentDurationMs: z - .number() - .min(0) - .optional() - .describe( - 'When set, only break down parent spans whose Duration ≥ this value. ' + - 'Use to focus the breakdown on slow parents (e.g. 1000 to only look ' + - 'at parents that took ≥ 1 second).', - ), - topN: z - .number() - .min(1) - .max(100) - .optional() - .default(20) - .describe( - 'Number of top operations to return, ranked by total_time_ms DESC. Default 20.', - ), - maxParentTraces: z - .number() - .min(100) - .max(1_000_000) - .optional() - .default(100_000) - .describe( - 'Safety cap on the number of distinct parent TraceIds considered. ' + - 'A breakdown over more than this many parent traces gets ' + - 'truncated to the first N. Default 100000.', - ), -}); - -type TraceBreakdownInput = z.infer; - -// ─── Tool ──────────────────────────────────────────────────────────────────── - -function durationDivisor(precision: number): number { - return Math.pow(10, Math.max(0, precision - 3)); -} - // The child stage looks spans up by TraceId, which is not in the sort key, so // it reads every span in the window regardless of how few parents matched. // Cost tracks the window length, so that is the first thing to shrink. @@ -130,51 +64,7 @@ export function registerTraceBreakdown({ { title: 'Top Time-Consuming Operations Across Matching Traces', annotations: { readOnlyHint: true }, - description: - 'Given a parent-span filter and a time window, return the child ' + - 'operations contributing the most cumulative time across all traces ' + - 'matching the parent filter. Same algorithm as the in-app ' + - '"Top Most Time Consuming Operations" chart on the service dashboard.\n\n' + - 'WHAT IT DOES (two-stage, runs as one SQL):\n' + - ' 1. Pick distinct TraceIds where the parent span matches ' + - '`parentFilter` in the window. Optionally restrict to ' + - '`minParentDurationMs` to focus on slow parents.\n' + - ' 2. Aggregate ALL spans across those traces (excluding the ' + - 'matching root span itself) by (ServiceName, SpanName), ranked by ' + - '`total_time_ms` DESC.\n\n' + - 'USE WHEN: investigating "where is the time going" for a slow ' + - 'operation. Filter to a specific (ServiceName, SpanName) pair and ' + - 'set `minParentDurationMs` to the threshold above which a parent ' + - 'span counts as "slow" for your investigation.\n\n' + - 'MULTIPLE OPERATIONS SLOW: when more than one operation shows ' + - 'elevated latency, call this tool ONCE PER (service, operation) ' + - 'and compare the top child rows across the result sets. Operations ' + - 'with the same top child likely share a cause; operations with ' + - 'different top children are independent regressions that happen ' + - 'to co-occur. DO NOT merge multiple operations into a single ' + - 'parentFilter — the cumulative rank then conflates independent ' + - 'investigations into one noisy answer.\n\n' + - 'RANKING METRIC: `total_time_ms = sum(Duration)` across all matching ' + - 'child spans. This captures the true contribution to elapsed time — ' + - 'a fast-but-frequent child can dominate the latency even if its p99 ' + - 'is unremarkable.\n\n' + - 'RETURNS: array of rows, each with `service`, `operation`, ' + - '`total_time_ms`, `calls`, `in_parents` (how many parent traces ' + - 'contained at least one such span), `p50_ms`, `p99_ms`. Plus a ' + - '`summary` block with the matched-parent count.\n\n' + - 'NEXT STEP after this tool: once a dominant slow child operation is ' + - 'identified, the canonical follow-up is clickstack_event_deltas with ' + - 'slow-vs-fast spans of THAT child operation as target/baseline ' + - "(target = {where: SpanName='' AND Duration > X}, " + - "baseline = {where: SpanName='' AND Duration <= Y}). " + - 'The ranked attributes surface what distinguishes slow invocations ' + - 'of the child operation from fast ones.\n\n' + - 'CROSS-SERVICE BREAKDOWN: this tool does NOT scope children to the ' + - "parent's service. Slow cross-service calls (database, cache, " + - 'upstream HTTP) surface naturally — useful for triage.\n\n' + - 'PAIR TOOL: clickstack_trace_waterfall returns ONE concrete trace as a ' + - "parent/child tree. Use it for an example after this tool's " + - 'aggregate breakdown has pointed you at the slow downstream operation.', + description: TRACE_BREAKDOWN_DESCRIPTION, inputSchema: traceBreakdownSchema, }, async (rawInput: TraceBreakdownInput) => { @@ -198,39 +88,25 @@ export function registerTraceBreakdown({ ); } - const connection = await getConnectionById( + const clickhouseClient = await getMcpClickhouseClient( teamId.toString(), source.connection.toString(), - true, ); - if (!connection) { + if (!clickhouseClient) { return mcpUserError( `Connection not found for source: ${input.sourceId}`, ); } - const clickhouseClient = new ClickhouseClient({ - host: connection.host, - username: connection.username, - password: connection.password, - requestTimeout: MCP_REQUEST_TIMEOUT, - }); - - // timeFilterExpr filters on every column of a multi-column - // timestampValueExpression and compares Date columns at day precision. - // Comparing a leading Date column (e.g. "EventDate, EventTime") against - // millisecond bounds would drop every span after midnight. + const timeFilterParams = { + connectionId: source.connection.toString(), + databaseName: source.from.databaseName, + tableName: source.from.tableName, + timestampValueExpression: source.timestampValueExpression, + metadata: getMetadata(clickhouseClient), + }; const renderTimeFilter = (start: number, end: number) => - timeFilterExpr({ - connectionId: source.connection.toString(), - databaseName: source.from.databaseName, - tableName: source.from.tableName, - timestampValueExpression: source.timestampValueExpression, - dateRange: [new Date(start), new Date(end)], - dateRangeStartInclusive: true, - dateRangeEndInclusive: true, - metadata: getMetadata(clickhouseClient), - }); + inclusiveTimeFilter(timeFilterParams, new Date(start), new Date(end)); let parentTimeFilter: ChSql; let childTimeFilter: ChSql; try { @@ -327,17 +203,7 @@ LIMIT {topN:UInt32} query_params: params, format: 'JSON', connectionId: source.connection.toString(), - // MCP settings win over source.querySettings so a source can't relax - // the max_execution_time ceiling, or the readonly guard that blocks - // DDL/DML injected through parentFilter. - clickhouse_settings: { - ...(source.querySettings - ? Object.fromEntries( - source.querySettings.map(s => [s.setting, s.value]), - ) - : {}), - ...MCP_CLICKHOUSE_SETTINGS, - }, + clickhouse_settings: mcpQuerySettings(source.querySettings), }); const json = (await ( result as { json: () => Promise<{ data: Row[] }> } diff --git a/packages/api/src/mcp/tools/trace/breakdownSchema.ts b/packages/api/src/mcp/tools/trace/breakdownSchema.ts new file mode 100644 index 0000000000..097608422c --- /dev/null +++ b/packages/api/src/mcp/tools/trace/breakdownSchema.ts @@ -0,0 +1,110 @@ +import { z } from 'zod'; + +export const traceBreakdownSchema = z.object({ + sourceId: z + .string() + .describe( + 'Trace source ID. Must be a source of kind="trace". ' + + 'Call clickstack_list_sources to find available sources.', + ), + parentFilter: z + .string() + .max(4096) + .describe( + 'SQL WHERE clause that selects the PARENT spans you want to break ' + + 'down. The tool finds the distinct TraceIds matching this filter, ' + + 'then aggregates all spans within those traces. ' + + 'Use SQL syntax (not Lucene). Example: ' + + "\"ServiceName = '' AND SpanName = ''\".\n\n" + + 'SCOPE TO A SPECIFIC OPERATION, not just a service. A service-only ' + + 'filter mixes every endpoint together and returns whatever has the ' + + "loudest child-time across all parents, which usually isn't what " + + 'you want. Always include a SpanName (or another operation-level ' + + 'discriminator). To compare two slow operations, call this tool ' + + 'once per operation and diff the results — two operations with ' + + "similar p99 don't necessarily share a slow child.", + ), + startTime: z + .string() + .describe('Start of the parent-filter time window as ISO 8601. REQUIRED.'), + endTime: z + .string() + .describe('End of the parent-filter time window as ISO 8601. REQUIRED.'), + minParentDurationMs: z + .number() + .min(0) + .optional() + .describe( + 'When set, only break down parent spans whose Duration ≥ this value. ' + + 'Use to focus the breakdown on slow parents (e.g. 1000 to only look ' + + 'at parents that took ≥ 1 second).', + ), + topN: z + .number() + .min(1) + .max(100) + .optional() + .default(20) + .describe( + 'Number of top operations to return, ranked by total_time_ms DESC. Default 20.', + ), + maxParentTraces: z + .number() + .min(100) + .max(1_000_000) + .optional() + .default(100_000) + .describe( + 'Safety cap on the number of distinct parent TraceIds considered. ' + + 'A breakdown over more than this many parent traces gets ' + + 'truncated to the first N. Default 100000.', + ), +}); + +export type TraceBreakdownInput = z.infer; + +export const TRACE_BREAKDOWN_DESCRIPTION = + 'Given a parent-span filter and a time window, return the child ' + + 'operations contributing the most cumulative time across all traces ' + + 'matching the parent filter. Same algorithm as the in-app ' + + '"Top Most Time Consuming Operations" chart on the service dashboard.\n\n' + + 'WHAT IT DOES (two-stage, runs as one SQL):\n' + + ' 1. Pick distinct TraceIds where the parent span matches ' + + '`parentFilter` in the window. Optionally restrict to ' + + '`minParentDurationMs` to focus on slow parents.\n' + + ' 2. Aggregate ALL spans across those traces (excluding the ' + + 'matching root span itself) by (ServiceName, SpanName), ranked by ' + + '`total_time_ms` DESC.\n\n' + + 'USE WHEN: investigating "where is the time going" for a slow ' + + 'operation. Filter to a specific (ServiceName, SpanName) pair and ' + + 'set `minParentDurationMs` to the threshold above which a parent ' + + 'span counts as "slow" for your investigation.\n\n' + + 'MULTIPLE OPERATIONS SLOW: when more than one operation shows ' + + 'elevated latency, call this tool ONCE PER (service, operation) ' + + 'and compare the top child rows across the result sets. Operations ' + + 'with the same top child likely share a cause; operations with ' + + 'different top children are independent regressions that happen ' + + 'to co-occur. DO NOT merge multiple operations into a single ' + + 'parentFilter — the cumulative rank then conflates independent ' + + 'investigations into one noisy answer.\n\n' + + 'RANKING METRIC: `total_time_ms = sum(Duration)` across all matching ' + + 'child spans. This captures the true contribution to elapsed time — ' + + 'a fast-but-frequent child can dominate the latency even if its p99 ' + + 'is unremarkable.\n\n' + + 'RETURNS: array of rows, each with `service`, `operation`, ' + + '`total_time_ms`, `calls`, `in_parents` (how many parent traces ' + + 'contained at least one such span), `p50_ms`, `p99_ms`. Plus a ' + + '`summary` block with the matched-parent count.\n\n' + + 'NEXT STEP after this tool: once a dominant slow child operation is ' + + 'identified, the canonical follow-up is clickstack_event_deltas with ' + + 'slow-vs-fast spans of THAT child operation as target/baseline ' + + "(target = {where: SpanName='' AND Duration > X}, " + + "baseline = {where: SpanName='' AND Duration <= Y}). " + + 'The ranked attributes surface what distinguishes slow invocations ' + + 'of the child operation from fast ones.\n\n' + + 'CROSS-SERVICE BREAKDOWN: this tool does NOT scope children to the ' + + "parent's service. Slow cross-service calls (database, cache, " + + 'upstream HTTP) surface naturally — useful for triage.\n\n' + + 'PAIR TOOL: clickstack_trace_waterfall returns ONE concrete trace as a ' + + "parent/child tree. Use it for an example after this tool's " + + 'aggregate breakdown has pointed you at the slow downstream operation.'; diff --git a/packages/api/src/mcp/tools/trace/shared.ts b/packages/api/src/mcp/tools/trace/shared.ts new file mode 100644 index 0000000000..499980c7cf --- /dev/null +++ b/packages/api/src/mcp/tools/trace/shared.ts @@ -0,0 +1,68 @@ +import type { ChSql } from '@hyperdx/common-utils/dist/clickhouse'; +import type { Metadata } from '@hyperdx/common-utils/dist/core/metadata'; +import { timeFilterExpr } from '@hyperdx/common-utils/dist/core/renderChartConfig'; +import type { QuerySettings } from '@hyperdx/common-utils/dist/types'; + +import { ClickhouseClient } from '@/clickhouse'; +import { getConnectionById } from '@/controllers/connection'; +import { + MCP_CLICKHOUSE_SETTINGS, + MCP_REQUEST_TIMEOUT, +} from '@/mcp/tools/query/helpers'; + +export function durationDivisor(precision: number): number { + // durationPrecision is the number of decimal digits in the stored value. + // precision=9 → ns (divide by 1e6 for ms), precision=6 → µs (divide by 1e3), + // precision=3 → already ms (divide by 1). + return Math.pow(10, Math.max(0, precision - 3)); +} + +export async function getMcpClickhouseClient( + teamId: string, + connectionId: string, +): Promise { + const connection = await getConnectionById(teamId, connectionId, true); + if (!connection) return null; + return new ClickhouseClient({ + host: connection.host, + username: connection.username, + password: connection.password, + requestTimeout: MCP_REQUEST_TIMEOUT, + }); +} + +// MCP settings win over source.querySettings so a source can't relax the +// max_execution_time ceiling, or the readonly guard that blocks DDL/DML +// injected through raw SQL filters. +export function mcpQuerySettings(querySettings: QuerySettings | undefined) { + return { + ...(querySettings + ? Object.fromEntries(querySettings.map(s => [s.setting, s.value])) + : {}), + ...MCP_CLICKHOUSE_SETTINGS, + }; +} + +export type TimeFilterParams = { + timestampValueExpression: string; + metadata: Metadata; + databaseName: string; + tableName: string; + connectionId: string; +}; + +// Filters on every column of a multi-column timestampValueExpression and +// compares Date columns at day precision, so a composite "EventDate, EventTime" +// source prunes on its Date column without dropping same-day rows. +export function inclusiveTimeFilter( + params: TimeFilterParams, + start: Date, + end: Date, +): Promise { + return timeFilterExpr({ + ...params, + dateRange: [start, end], + dateRangeStartInclusive: true, + dateRangeEndInclusive: true, + }); +} diff --git a/packages/api/src/mcp/tools/trace/waterfall.ts b/packages/api/src/mcp/tools/trace/waterfall.ts index cd79e7a498..f59cb1eb18 100644 --- a/packages/api/src/mcp/tools/trace/waterfall.ts +++ b/packages/api/src/mcp/tools/trace/waterfall.ts @@ -1,9 +1,5 @@ import type { ChSql } from '@hyperdx/common-utils/dist/clickhouse'; -import { - getMetadata, - type Metadata, -} from '@hyperdx/common-utils/dist/core/metadata'; -import { timeFilterExpr } from '@hyperdx/common-utils/dist/core/renderChartConfig'; +import { getMetadata } from '@hyperdx/common-utils/dist/core/metadata'; import { pickBucketTimestampColumn } from '@hyperdx/common-utils/dist/core/utils'; import { type BuilderChartConfigWithDateRange, @@ -14,15 +10,20 @@ import { } from '@hyperdx/common-utils/dist/types'; import { z } from 'zod'; -import { ClickhouseClient } from '@/clickhouse'; -import { getConnectionById } from '@/controllers/connection'; +import type { ClickhouseClient } from '@/clickhouse'; import { getSource } from '@/controllers/sources'; import { clickHouseErrorResult, MCP_CLICKHOUSE_SETTINGS, - MCP_REQUEST_TIMEOUT, parseTimeRange, } from '@/mcp/tools/query/helpers'; +import { + durationDivisor, + getMcpClickhouseClient, + inclusiveTimeFilter, + mcpQuerySettings, + type TimeFilterParams, +} from '@/mcp/tools/trace/shared'; import type { ToolRegistrar } from '@/mcp/tools/types'; import { mcpUserError } from '@/mcp/utils/errors'; import logger from '@/utils/logger'; @@ -190,13 +191,6 @@ function buildPreOrderTree(spans: SpanRow[]): TreeSpan[] { return ordered; } -function durationDivisor(precision: number): number { - // durationPrecision is the number of decimal digits in the stored value. - // precision=9 → ns (divide by 1e6 for ms), precision=6 → µs (divide by 1e3), - // precision=3 → already ms (divide by 1). - return Math.pow(10, Math.max(0, precision - 3)); -} - // min()/max() over an empty set yields the epoch, i.e. 0. function parseProbeTimestamp( value: string | number | undefined, @@ -206,31 +200,6 @@ function parseProbeTimestamp( return isNaN(ms) || ms <= 0 ? null : ms; } -async function getMcpClickhouseClient( - teamId: string, - connectionId: string, -): Promise { - const connection = await getConnectionById(teamId, connectionId, true); - if (!connection) return null; - return new ClickhouseClient({ - host: connection.host, - username: connection.username, - password: connection.password, - requestTimeout: MCP_REQUEST_TIMEOUT, - }); -} - -// MCP settings win over source.querySettings so a source can't relax the -// max_execution_time / readonly ceiling this tool depends on. -function mcpQuerySettings(querySettings: QuerySettings | undefined) { - return { - ...(querySettings - ? Object.fromEntries(querySettings.map(s => [s.setting, s.value])) - : {}), - ...MCP_CLICKHOUSE_SETTINGS, - }; -} - type TimestampExprs = { /** Highest-precision DateTime column, for event-time SELECT/ORDER BY. */ eventTs: string; @@ -239,23 +208,13 @@ type TimestampExprs = { timeFilter: (start: Date, end: Date) => Promise; }; -async function resolveTimestampExprs(params: { - timestampValueExpression: string; - metadata: Metadata; - databaseName: string; - tableName: string; - connectionId: string; -}): Promise { +async function resolveTimestampExprs( + params: TimeFilterParams, +): Promise { const eventTs = await pickBucketTimestampColumn(params); return { eventTs, - timeFilter: (start, end) => - timeFilterExpr({ - ...params, - dateRange: [start, end], - dateRangeStartInclusive: true, - dateRangeEndInclusive: true, - }), + timeFilter: (start, end) => inclusiveTimeFilter(params, start, end), }; } From 9cfa58a66c59692f662e7dbe9c6aafd3ff499cf4 Mon Sep 17 00:00:00 2001 From: Brandon Pereira Date: Thu, 1 Oct 2026 17:12:12 -0600 Subject: [PATCH 10/10] fix(mcp): don't give query-tuning advice for socket timeouts - isQueryOutOfTime excludes socket ETIMEDOUT (ClickHouse unreachable) from the execution-time hint and the breakdown timeout suffix (greptile P2). - Connection/server errors in the breakdown query no longer get the invalid-SQL suffix either. - Metadata-lookup failures drop the 'shorten the window' suffix; those DESCRIBE queries don't depend on the window or filters (inline minor). - Restore main's timeout regex; the 'Timeout error.' alternative was dead since errorHint always gets the error object (inline minor). --- packages/api/src/mcp/__tests__/query.test.ts | 8 ++-- .../api/src/mcp/__tests__/trace.int.test.ts | 37 ++++++++++++++----- packages/api/src/mcp/tools/query/helpers.ts | 28 ++++++++++---- packages/api/src/mcp/tools/trace/breakdown.ts | 16 ++++---- 4 files changed, 61 insertions(+), 28 deletions(-) diff --git a/packages/api/src/mcp/__tests__/query.test.ts b/packages/api/src/mcp/__tests__/query.test.ts index ec6a52dd5b..585ea7551f 100644 --- a/packages/api/src/mcp/__tests__/query.test.ts +++ b/packages/api/src/mcp/__tests__/query.test.ts @@ -310,14 +310,14 @@ describe('errorHint', () => { }); it('should match the client-side request timeout', () => { - const hint = errorHint('Timeout error.'); - expect(hint).toContain('execution-time limit'); + const error = new Error('Timeout error.'); + expect(errorHint(error.message, error)).toContain('execution-time limit'); }); - it('should match a socket timeout from the error object', () => { + it('should not give query-tuning advice for a socket timeout', () => { const error: NodeJS.ErrnoException = new Error('connect ETIMEDOUT'); error.code = 'ETIMEDOUT'; - expect(errorHint(error.message, error)).toContain('execution-time limit'); + expect(errorHint(error.message, error)).toBeNull(); }); it('should match SETTING_CONSTRAINT_VIOLATION errors', () => { diff --git a/packages/api/src/mcp/__tests__/trace.int.test.ts b/packages/api/src/mcp/__tests__/trace.int.test.ts index 61f2737521..722af8b2bd 100644 --- a/packages/api/src/mcp/__tests__/trace.int.test.ts +++ b/packages/api/src/mcp/__tests__/trace.int.test.ts @@ -1407,9 +1407,34 @@ describe('MCP Trace Tools', () => { }), ], ])('returns actionable guidance on a %s', async (_label, error) => { + const text = await callBreakdownWithFailingQuery(error); + expect(text).toContain('Failed to compute breakdown'); + expect(text).toContain('execution-time limit'); + expect(text).toContain('shorter startTime/endTime window'); + expect(text).toContain('minParentDurationMs'); + expect(text).not.toContain('must be valid ClickHouse SQL'); + }); + + it('gives no query-tuning or invalid-SQL advice on a socket timeout', async () => { + const error: NodeJS.ErrnoException = new Error('connect ETIMEDOUT'); + error.code = 'ETIMEDOUT'; + const text = await callBreakdownWithFailingQuery(error); + expect(text).toContain('Failed to compute breakdown'); + expect(text).not.toContain('execution-time limit'); + expect(text).not.toContain('shorter startTime/endTime window'); + expect(text).not.toContain('must be valid ClickHouse SQL'); + }); + + async function callBreakdownWithFailingQuery(error: Error) { + const original = ClickhouseClient.prototype.query; const querySpy = jest .spyOn(ClickhouseClient.prototype, 'query') - .mockRejectedValue(error); + .mockImplementation(function (this: ClickhouseClient, args) { + if (args.query.includes('parent_traces')) { + return Promise.reject(error); + } + return original.call(this, args); + }); try { const result = await callTool( client, @@ -1421,18 +1446,12 @@ describe('MCP Trace Tools', () => { endTime: new Date(now.getTime() + 60 * 1000).toISOString(), }, ); - expect(result.isError).toBe(true); - const text = getFirstText(result); - expect(text).toContain('Failed to compute breakdown'); - expect(text).toContain('execution-time limit'); - expect(text).toContain('shorter startTime/endTime window'); - expect(text).toContain('minParentDurationMs'); - expect(text).not.toContain('must be valid ClickHouse SQL'); + return getFirstText(result); } finally { querySpy.mockRestore(); } - }); + } }); }); }); diff --git a/packages/api/src/mcp/tools/query/helpers.ts b/packages/api/src/mcp/tools/query/helpers.ts index 418e4364e1..e04de47410 100644 --- a/packages/api/src/mcp/tools/query/helpers.ts +++ b/packages/api/src/mcp/tools/query/helpers.ts @@ -870,13 +870,19 @@ function findCause( return undefined; } -// Match only real timeouts. A bare `max_execution_time` substring would also -// hijack SETTING_CONSTRAINT_VIOLATION / readonly errors ("Setting -// max_execution_time shouldn't be greater than…"), which need a different fix. -// "Timeout error." is what @clickhouse/client throws when the HTTP request -// timeout fires before ClickHouse answers. -const QUERY_TIMEOUT_RE = - /TIMEOUT_EXCEEDED|Timeout exceeded|^Timeout error\.?$/i; +const SOCKET_TIMEOUT_CODES: ReadonlySet = new Set(['ETIMEDOUT']); + +/** + * True when a query ran out of time: ClickHouse's max_execution_time or the + * client request timeout. A socket ETIMEDOUT is excluded because ClickHouse + * was unreachable, so narrowing the query won't help. + */ +export function isQueryOutOfTime(e: unknown): boolean { + const socketTimeout = findCause(e, (c): c is Error => + hasNodeErrorCode(c, SOCKET_TIMEOUT_CODES), + ); + return !socketTimeout && isQueryTimeoutError(e); +} /** @internal Exported for testing only. */ export function errorHint(msg: string, error?: unknown): string | null { @@ -917,7 +923,13 @@ export function errorHint(msg: string, error?: unknown): string | null { 'The result row count is too large to serialize back to the agent.' ); } - if (QUERY_TIMEOUT_RE.test(msg) || isQueryTimeoutError(error)) { + // Match only real timeouts. A bare `max_execution_time` substring would also + // hijack SETTING_CONSTRAINT_VIOLATION / readonly errors ("Setting + // max_execution_time shouldn't be greater than…"), which need a different fix. + if ( + /TIMEOUT_EXCEEDED|Timeout exceeded/i.test(msg) || + isQueryOutOfTime(error) + ) { return ( 'The query exceeded its execution-time limit. Narrow the time range so ' + 'ClickHouse can prune partitions, add filters to reduce the rows scanned, ' + diff --git a/packages/api/src/mcp/tools/trace/breakdown.ts b/packages/api/src/mcp/tools/trace/breakdown.ts index 7cd7201d19..9a7263097d 100644 --- a/packages/api/src/mcp/tools/trace/breakdown.ts +++ b/packages/api/src/mcp/tools/trace/breakdown.ts @@ -22,6 +22,8 @@ import { SourceKind } from '@hyperdx/common-utils/dist/types'; import { getSource } from '@/controllers/sources'; import { clickHouseErrorResult, + isQueryOutOfTime, + isServerError, parseTimeRange, } from '@/mcp/tools/query/helpers'; import { @@ -37,7 +39,6 @@ import { } from '@/mcp/tools/trace/shared'; import type { ToolRegistrar } from '@/mcp/tools/types'; import { mcpUserError } from '@/mcp/utils/errors'; -import { isQueryTimeoutError } from '@/tasks/checkAlerts/errors'; // The child stage looks spans up by TraceId, which is not in the sort key, so // it reads every span in the window regardless of how few parents matched. @@ -121,10 +122,9 @@ export function registerTraceBreakdown({ ), ]); } catch (e) { - return clickHouseErrorResult(e, { - prefix: 'Failed to compute breakdown', - suffix: isQueryTimeoutError(e) ? TIMEOUT_SUFFIX : undefined, - }); + // Only the DESCRIBE lookups run here; they don't depend on the window or + // filters, so neither suffix applies. + return clickHouseErrorResult(e, 'Failed to compute breakdown'); } // Source-configured SQL expressions. These are trusted (set by the @@ -212,9 +212,11 @@ LIMIT {topN:UInt32} } catch (e) { return clickHouseErrorResult(e, { prefix: 'Failed to compute breakdown', - suffix: isQueryTimeoutError(e) + suffix: isQueryOutOfTime(e) ? TIMEOUT_SUFFIX - : INVALID_FILTER_SUFFIX, + : isServerError(e) + ? undefined + : INVALID_FILTER_SUFFIX, }); }