Skip to content

Commit cbce1e5

Browse files
committed
fix(logs): match copilot log-grep patterns literally, never as a regex
`grepSpans` compiled a caller-supplied pattern with a bare `new RegExp`, whose only guard was a `catch` for syntax errors. Trace text is attacker-influenced — a workflow can emit arbitrarily long uniform runs into its own block outputs — and matching runs synchronously on the shared event loop, so an authenticated caller could choose both the pattern and the input and stall every request on the instance. Patterns are now matched as an escaped, case-insensitive literal. Screening was implemented first and abandoned, because each rule only excludes the shapes someone thought to enumerate: - `safe-regex2` (already used by the guardrails validator) documents itself as having false negatives. It screens star height only, so it passes `(a|a)*b`, measured >61s on V8 at 30 characters. - Rejecting quantified groups on top of that catches `(a|a)*b`, and every attack `safe-regex2` catches, but still passes `a*a*b` — adjacent quantifiers over overlapping character sets — measured 213s on JSC and 132s on V8 over a 10k-character run, well inside what a block output can hold. An escaped literal is linear on every engine, needs no dependency, and does not depend on which runtime serves the request. `safe-regex2` stays a dependency for its existing guardrails/PII callers; it is simply not relied on here. `query_logs` loses regex matching. Its catalog entry describes `pattern` as "greps" rather than promising regex, but it is generated from a contract in another repository and cannot be updated here, so a `patternNotice` is returned whenever a pattern contains regex syntax — the caller is told the pattern was taken literally instead of reading zero matches as "not in the trace". Two bounds are kept as backstops: a cumulative match-time budget charging only time inside `test`/`exec` (never the blob-store reads the scan awaits between matches, which would truncate slow-but-legitimate greps under load), and a total scanned-character cap.
1 parent 4edc169 commit cbce1e5

3 files changed

Lines changed: 179 additions & 15 deletions

File tree

apps/sim/lib/copilot/tools/server/workflow/query-logs.ts

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -145,12 +145,17 @@ export const queryLogsServerTool: BaseServerTool<QueryLogsArgs, unknown> = {
145145

146146
if (args.pattern) {
147147
logger.info('query_logs grep', { workspaceId, executionId: args.executionId })
148-
const { matches, truncated } = await grepSpans(traceSpans, args.pattern, viewCtx)
148+
const { matches, truncated, patternNotice } = await grepSpans(
149+
traceSpans,
150+
args.pattern,
151+
viewCtx
152+
)
149153
return {
150154
executionId: detail.executionId,
151155
workflowId: detail.workflowId,
152156
status: detail.status,
153157
pattern: args.pattern,
158+
...(patternNotice ? { patternNotice } : {}),
154159
matches,
155160
truncated,
156161
}

apps/sim/lib/logs/log-views.test.ts

Lines changed: 72 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@ vi.mock('@/lib/execution/payloads/store', () => ({
3232
materializeLargeValueRef: materializeLargeValueRefMock,
3333
}))
3434

35+
import { sleep } from '@sim/utils/helpers'
3536
import type { TraceSpan } from '@/lib/logs/types'
3637
import { grepSpans, type LogViewContext, toFull, toOverview } from './log-views'
3738

@@ -169,10 +170,80 @@ describe('grepSpans', () => {
169170
expect(result.matches.some((m) => m.field === 'output')).toBe(true)
170171
})
171172

172-
it('falls back to literal substring on invalid regex', async () => {
173+
it('matches regex syntax literally rather than interpreting it', async () => {
173174
const spans = [span({ output: { v: 'value a(b found' } })]
174175
const result = await grepSpans(spans, '(', ctx)
175176
expect(result.matches.some((m) => m.field === 'output')).toBe(true)
177+
expect(result.patternNotice).toContain('literal')
178+
})
179+
180+
it('does not interpret a regex pattern, and says so', async () => {
181+
const spans = [span({ output: { v: 'status=503' } })]
182+
183+
// Literal 'status=\d+' is not present; the regex it denotes would have matched.
184+
const asRegex = await grepSpans(spans, 'status=\\d+', ctx)
185+
expect(asRegex.matches).toEqual([])
186+
expect(asRegex.patternNotice).toContain('literal')
187+
188+
const asLiteral = await grepSpans(spans, 'status=503', ctx)
189+
expect(asLiteral.matches.some((m) => m.field === 'output')).toBe(true)
190+
expect(asLiteral.patternNotice).toBeUndefined()
191+
})
192+
193+
it.each([
194+
['nested quantifier', '(a+)+$'],
195+
['duplicate alternation, passes safe-regex2', '(a|a)*b'],
196+
['adjacent quantifiers, passes every structural screen', 'a*a*b'],
197+
])('never executes a catastrophic pattern (%s)', async (_label, pattern) => {
198+
// Each of these blocks the event loop for minutes if compiled as a regex:
199+
// `a*a*b` measured 213s on JSC / 132s on V8 over a 10k-character run.
200+
const spans = [span({ output: { v: `${'a'.repeat(5000)}!` } })]
201+
202+
const start = Date.now()
203+
const result = await grepSpans(spans, pattern, ctx)
204+
const elapsedMs = Date.now() - start
205+
206+
expect(elapsedMs).toBeLessThan(1000)
207+
expect(result.matches).toEqual([])
208+
})
209+
210+
it('matches a long pattern literally without a length cap', async () => {
211+
const pattern = `${'x'.repeat(600)}needle`
212+
const spans = [span({ output: { v: pattern } })]
213+
const result = await grepSpans(spans, pattern, ctx)
214+
expect(result.matches.some((m) => m.field === 'output')).toBe(true)
215+
})
216+
217+
it('stops scanning and marks truncated once the character budget is exhausted', async () => {
218+
const spans = [
219+
span({ id: 'a', output: { v: 'x'.repeat(400) } }),
220+
span({ id: 'b', output: { v: 'needle' } }),
221+
]
222+
const result = await grepSpans(spans, 'needle', ctx, { maxScannedChars: 100 })
223+
expect(result.matches).toEqual([])
224+
expect(result.truncated).toBe(true)
225+
})
226+
227+
it('stops scanning and marks truncated once the match-time budget is exhausted', async () => {
228+
const spans = [span({ output: { v: 'needle' } })]
229+
const result = await grepSpans(spans, 'needle', ctx, { matchTimeBudgetMs: 0 })
230+
expect(result.matches).toEqual([])
231+
expect(result.truncated).toBe(true)
232+
})
233+
234+
it('does not charge blob-store I/O to the match-time budget', async () => {
235+
// Each slice read sleeps well past the budget: only time spent matching
236+
// counts, so a slow-but-legitimate grep must still return complete results.
237+
readLargeArrayManifestSliceMock.mockImplementation(async (_m: unknown, start: number) => {
238+
await sleep(30)
239+
return start === 400 ? [{ v: 'found the needle here' }] : [{ v: 'nothing' }]
240+
})
241+
const spans = [span({ output: manifest(500) as any })]
242+
243+
const result = await grepSpans(spans, 'needle', ctx, { matchTimeBudgetMs: 50 })
244+
245+
expect(result.matches.some((m) => m.field === 'output')).toBe(true)
246+
expect(result.truncated).toBe(false)
176247
})
177248

178249
it('returns empty for empty traceSpans', async () => {

apps/sim/lib/logs/log-views.ts

Lines changed: 101 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,23 @@ const DEFAULT_MAX_MATCHES = 50
2323
const DEFAULT_MAX_SNIPPET_CHARS = 500
2424
const DEFAULT_MAX_SLICES_SCANNED = 200
2525

26+
/**
27+
* Cumulative time the pattern itself may spend matching, across all spans/fields.
28+
*
29+
* Deliberately counts only time inside `test`/`exec`, not the grep's wall clock:
30+
* the scan awaits blob-store reads (array slices, large-value refs) between
31+
* matches, and charging that I/O to the budget would truncate slow-but-legitimate
32+
* greps under load. Matching is the only part that occupies the event loop, so
33+
* it is the only part worth bounding.
34+
*/
35+
const DEFAULT_MATCH_TIME_BUDGET_MS = 5_000
36+
/**
37+
* Total characters a single grep may run the pattern over. A backstop against a
38+
* pattern that slips past the backtracking screen being amplified across every
39+
* slice — set well above any realistic trace so normal greps never trip it.
40+
*/
41+
const DEFAULT_MAX_SCANNED_CHARS = 64 * 1024 * 1024
42+
2643
// ---------------------------------------------------------------------------
2744
// Overview (Level 2): block tree with timing + cost, NO input/output.
2845
// ---------------------------------------------------------------------------
@@ -172,38 +189,85 @@ export interface GrepSpanMatch {
172189
export interface GrepSpansResult {
173190
matches: GrepSpanMatch[]
174191
truncated: boolean
192+
/**
193+
* Present when the pattern contained regex syntax, which is matched literally.
194+
* The tool catalog cannot say so up front — it is generated from a contract in
195+
* another repository — so the caller is told here instead of silently reading
196+
* zero matches as "not present in the trace".
197+
*/
198+
patternNotice?: string
175199
}
176200

177201
export interface GrepSpansOptions {
178202
maxMatches?: number
179203
maxSnippetChars?: number
180204
maxSlicesScanned?: number
205+
maxScannedChars?: number
206+
matchTimeBudgetMs?: number
181207
}
182208

183209
interface GrepState {
184210
matches: GrepSpanMatch[]
185211
slicesScanned: number
212+
scannedChars: number
213+
matchTimeMs: number
186214
truncated: boolean
187215
maxMatches: number
188216
maxSnippetChars: number
189217
maxSlicesScanned: number
218+
maxScannedChars: number
219+
matchTimeBudgetMs: number
190220
regex: RegExp
191221
}
192222

193223
function escapeRegExp(input: string): string {
194224
return input.replace(/[.*+?^${}()|[\]\\]/g, '\\$&')
195225
}
196226

197-
function buildRegex(pattern: string): RegExp {
227+
/** Regex syntax in a pattern signals the caller expected regex semantics. */
228+
const REGEX_METACHARACTERS = /[.*+?^${}()|[\]\\]/
229+
230+
/**
231+
* Compile a caller-supplied grep pattern as a case-insensitive literal.
232+
*
233+
* Caller patterns are deliberately never executed as regexes. Trace text is
234+
* attacker-influenced — a workflow can emit arbitrarily long uniform runs into
235+
* its own block outputs — and matching runs synchronously on the shared event
236+
* loop, so a backtracking pattern stalls every request on the instance.
237+
*
238+
* Screening was tried and abandoned: `safe-regex2` (which the guardrails
239+
* validator uses) documents itself as having false negatives and passes
240+
* `(a|a)*b`; rejecting quantified groups on top of it still passes `a*a*b`,
241+
* measured at 213s on JSC and 132s on V8 over a 10k-character run. Each rule
242+
* only excludes the shapes someone thought to enumerate. An escaped literal is
243+
* linear on every engine, which is the one property worth relying on here.
244+
*/
245+
function compilePattern(pattern: string): { regex: RegExp; notice?: string } {
246+
const regex = new RegExp(escapeRegExp(pattern), 'i')
247+
if (!REGEX_METACHARACTERS.test(pattern)) return { regex }
248+
return {
249+
regex,
250+
notice:
251+
'Matched as a literal, case-insensitive substring — regex syntax is not interpreted. Search for the literal text you expect to see in the trace.',
252+
}
253+
}
254+
255+
/**
256+
* Charge the elapsed matching time to the grep's budget. Every `test`/`exec` on
257+
* caller-supplied patterns goes through here.
258+
*/
259+
function runTimed<T>(state: GrepState, match: (regex: RegExp) => T): T {
260+
const started = performance.now()
198261
try {
199-
return new RegExp(pattern, 'i')
200-
} catch {
201-
return new RegExp(escapeRegExp(pattern), 'i')
262+
state.regex.lastIndex = 0
263+
return match(state.regex)
264+
} finally {
265+
state.matchTimeMs += performance.now() - started
202266
}
203267
}
204268

205-
function snippetAround(text: string, regex: RegExp, maxChars: number): string {
206-
const m = regex.exec(text)
269+
function snippetAround(text: string, state: GrepState, maxChars: number): string {
270+
const m = runTimed(state, (regex) => regex.exec(text))
207271
const index = m ? m.index : 0
208272
const half = Math.floor(maxChars / 2)
209273
const start = Math.max(0, index - half)
@@ -214,7 +278,12 @@ function snippetAround(text: string, regex: RegExp, maxChars: number): string {
214278
}
215279

216280
function done(state: GrepState): boolean {
217-
return state.truncated || state.matches.length >= state.maxMatches
281+
if (state.truncated || state.matches.length >= state.maxMatches) return true
282+
if (state.matchTimeMs >= state.matchTimeBudgetMs) {
283+
state.truncated = true
284+
return true
285+
}
286+
return false
218287
}
219288

220289
function recordIfMatch(
@@ -224,15 +293,18 @@ function recordIfMatch(
224293
state: GrepState
225294
): void {
226295
if (done(state)) return
227-
state.regex.lastIndex = 0
228-
if (!state.regex.test(text)) return
229-
state.regex.lastIndex = 0
296+
if (state.scannedChars + text.length > state.maxScannedChars) {
297+
state.truncated = true
298+
return
299+
}
300+
state.scannedChars += text.length
301+
if (!runTimed(state, (regex) => regex.test(text))) return
230302
state.matches.push({
231303
spanId: span.id,
232304
blockId: span.blockId,
233305
name: span.name,
234306
field,
235-
snippet: snippetAround(text, state.regex, state.maxSnippetChars),
307+
snippet: snippetAround(text, state, state.maxSnippetChars),
236308
})
237309
if (state.matches.length >= state.maxMatches) state.truncated = true
238310
}
@@ -305,21 +377,33 @@ function safeStringify(value: unknown): string {
305377
* directly; large-array I/O is streamed slice-by-slice (each released before the
306378
* next); single large refs are materialized under a byte cap (falling back to
307379
* the ref preview). Only bounded match snippets are accumulated.
380+
*
381+
* `pattern` is matched as a literal substring, never as a regex — see
382+
* `compilePattern`. Two budgets bound the scan on top of that: a total
383+
* character budget and a cumulative match-time budget. Neither counts the
384+
* blob-store I/O this scan awaits, so a slow-but-legitimate grep is not
385+
* truncated for being slow. With literal matching both are backstops rather
386+
* than load-bearing, and they stay to bound total work per request.
308387
*/
309388
export async function grepSpans(
310389
spans: TraceSpan[],
311390
pattern: string,
312391
ctx: LogViewContext,
313392
opts?: GrepSpansOptions
314393
): Promise<GrepSpansResult> {
394+
const compiled = compilePattern(pattern)
315395
const state: GrepState = {
316396
matches: [],
317397
slicesScanned: 0,
398+
scannedChars: 0,
399+
matchTimeMs: 0,
318400
truncated: false,
319401
maxMatches: opts?.maxMatches ?? DEFAULT_MAX_MATCHES,
320402
maxSnippetChars: opts?.maxSnippetChars ?? DEFAULT_MAX_SNIPPET_CHARS,
321403
maxSlicesScanned: opts?.maxSlicesScanned ?? DEFAULT_MAX_SLICES_SCANNED,
322-
regex: buildRegex(pattern),
404+
maxScannedChars: opts?.maxScannedChars ?? DEFAULT_MAX_SCANNED_CHARS,
405+
matchTimeBudgetMs: opts?.matchTimeBudgetMs ?? DEFAULT_MATCH_TIME_BUDGET_MS,
406+
regex: compiled.regex,
323407
}
324408

325409
const walk = async (list: TraceSpan[]): Promise<void> => {
@@ -335,5 +419,9 @@ export async function grepSpans(
335419
}
336420

337421
await walk(spans)
338-
return { matches: state.matches, truncated: state.truncated }
422+
return {
423+
matches: state.matches,
424+
truncated: state.truncated,
425+
...(compiled.notice ? { patternNotice: compiled.notice } : {}),
426+
}
339427
}

0 commit comments

Comments
 (0)