Skip to content

Commit 189a0c7

Browse files
committed
fix(logs): keep trace secret projection from blocking the event loop
Projection is CPU-bound and its awaits settle as microtasks, so a large trace, or a page of them projected concurrently for a logs read with trace spans, held the whole Node process until it finished. Every other request on that process stalled behind it. - Yield a macrotask from each content field once a 10ms slice expires. The slice is process-wide and handed to one waiting projection per event-loop turn, so a turn stays bounded whatever the concurrency. - Run the whole-trace content invariant per span, in projection pre-order, against one shared budget. An over-budget trace now fails at the span that crosses the budget instead of after projecting the whole trace and then discarding it. Output is unchanged.
1 parent 003c352 commit 189a0c7

2 files changed

Lines changed: 96 additions & 10 deletions

File tree

‎apps/sim/lib/logs/execution/trace-secret-projection.test.ts‎

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -340,6 +340,34 @@ describe('projectTraceSpansForSecrets', () => {
340340
expect(result[0].output).toEqual({ value: 'prefix {{LONG}} suffix' })
341341
})
342342

343+
it('lets pending macrotasks run mid-projection and still projects every span', async () => {
344+
const spans = Array.from({ length: 30 }, (_, spanIndex) =>
345+
createSpan({
346+
id: `span-${spanIndex}`,
347+
output: {
348+
rows: Array.from({ length: 400 }, (_, row) => ({
349+
name: `row ${row}`,
350+
note: 'contains secretval inline',
351+
})),
352+
},
353+
})
354+
)
355+
let macrotaskRan = false
356+
setImmediate(() => {
357+
macrotaskRan = true
358+
})
359+
360+
const projected = await projectTraceSpansForSecrets(spans, {
361+
registry: createRegistry([{ plaintext: 'secretval', replacement: '{{SECRET}}' }]),
362+
store: STORE,
363+
})
364+
365+
expect(macrotaskRan).toBe(true)
366+
expect(projected[29].output).toEqual({
367+
rows: expect.arrayContaining([{ name: 'row 399', note: 'contains {{SECRET}} inline' }]),
368+
})
369+
})
370+
343371
it('projects a successfully resolved numeric Function result without mutating runtime output', async () => {
344372
const runtimeOutput = { result: 12345678, unchanged: 5678 }
345373
const source = createSpan({ output: runtimeOutput })

‎apps/sim/lib/logs/execution/trace-secret-projection.ts‎

Lines changed: 68 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ const MAX_LARGE_VALUES = 1_024
3636
const MAX_LARGE_VALUE_CHAIN_DEPTH = 32
3737
const MAX_LARGE_MANIFEST_CHUNKS = MAX_LARGE_VALUES
3838
const MAX_LARGE_MANIFEST_ITEMS = MAX_CONTENT_NODES
39+
const PROJECTION_SLICE_MS = 10
3940
const OMIT = Symbol('omit-trace-content')
4041
const LARGE_VALUE_REF_KEYS = new Set([
4142
LARGE_VALUE_REF_MARKER,
@@ -167,6 +168,38 @@ function createProjectionContext(
167168
}
168169
}
169170

171+
let projectionSliceEndsAt = 0
172+
let projectionTurnScheduled = false
173+
const projectionTurnQueue: Array<() => void> = []
174+
175+
/**
176+
* Projection is CPU-bound and its awaits settle as microtasks, which never let the event loop
177+
* service I/O, so without a macrotask yield one large trace — or a page of them projected
178+
* concurrently — holds the whole process until it finishes.
179+
*
180+
* The slice is process-wide and handed to one waiting projection per event-loop turn: releasing
181+
* them together would let each finish its in-flight field before I/O runs again, so a turn would
182+
* grow with concurrency instead of staying at one slice plus one field.
183+
*/
184+
async function yieldWhenSliceExpires(): Promise<void> {
185+
if (performance.now() < projectionSliceEndsAt) return
186+
await new Promise<void>((resolve) => {
187+
projectionTurnQueue.push(resolve)
188+
scheduleProjectionTurn()
189+
})
190+
}
191+
192+
function scheduleProjectionTurn(): void {
193+
if (projectionTurnScheduled) return
194+
projectionTurnScheduled = true
195+
setImmediate(() => {
196+
projectionTurnScheduled = false
197+
projectionSliceEndsAt = performance.now() + PROJECTION_SLICE_MS
198+
projectionTurnQueue.shift()?.()
199+
if (projectionTurnQueue.length > 0) scheduleProjectionTurn()
200+
})
201+
}
202+
170203
function visitNode(state: TraversalState, depth: number): void {
171204
state.nodes += 1
172205
if (state.nodes > MAX_CONTENT_NODES) {
@@ -800,6 +833,7 @@ async function sanitizeContentField(
800833
value: unknown,
801834
context: ProjectionContext
802835
): Promise<unknown | typeof OMIT> {
836+
await yieldWhenSliceExpires()
803837
try {
804838
return await sanitizeMaterializedValue(value, context)
805839
} catch (error) {
@@ -913,7 +947,8 @@ async function sanitizeTraceSpan(
913947
span: TraceSpan,
914948
context: ProjectionContext,
915949
depth: number,
916-
state: BoundedTraceStructureState
950+
state: BoundedTraceStructureState,
951+
assertContentIsSafe: SpanContentAssertion
917952
): Promise<TraceSpan> {
918953
if (!takeTraceStructureNode(state, depth)) {
919954
throw new TraceSecretProjectionError('Trace span structure limit exceeded')
@@ -954,11 +989,13 @@ async function sanitizeTraceSpan(
954989
projected.providerTiming = { ...span.providerTiming, segments }
955990
}
956991

992+
assertContentIsSafe(projected, depth)
993+
957994
if (span.children !== undefined) {
958995
assertTraceStructureArrayFits(span.children, state)
959996
const children: TraceSpan[] = []
960997
for (const child of span.children) {
961-
children.push(await sanitizeTraceSpan(child, context, depth + 1, state))
998+
children.push(await sanitizeTraceSpan(child, context, depth + 1, state, assertContentIsSafe))
962999
}
9631000
projected.children = children
9641001
}
@@ -1278,11 +1315,12 @@ function assertNoPlaintext(
12781315

12791316
type TraceContentVisitor = (value: unknown) => void
12801317

1281-
function visitTraceSpanContent(
1318+
/** Visits one span's content, not its children's; `visitTraceSpanContent` descends from here. */
1319+
function visitTraceSpanOwnContent(
12821320
span: TraceSpan,
12831321
visit: TraceContentVisitor,
12841322
structureState: BoundedTraceStructureState,
1285-
depth = 0
1323+
depth: number
12861324
): void {
12871325
if (!takeTraceStructureNode(structureState, depth)) {
12881326
throw new TraceSecretProjectionError('Trace invariant structure limit exceeded')
@@ -1335,6 +1373,15 @@ function visitTraceSpanContent(
13351373
}
13361374
}
13371375
assertTraceStructureArrayFits(span.children ?? [], structureState)
1376+
}
1377+
1378+
function visitTraceSpanContent(
1379+
span: TraceSpan,
1380+
visit: TraceContentVisitor,
1381+
structureState: BoundedTraceStructureState,
1382+
depth = 0
1383+
): void {
1384+
visitTraceSpanOwnContent(span, visit, structureState, depth)
13381385
for (const child of span.children ?? []) {
13391386
visitTraceSpanContent(child, visit, structureState, depth + 1)
13401387
}
@@ -1348,12 +1395,23 @@ function visitTraceSpansContent(traceSpans: TraceSpan[], visit: TraceContentVisi
13481395
}
13491396
}
13501397

1351-
function assertTraceSpansContentIsSafe(
1352-
traceSpans: TraceSpan[],
1398+
type SpanContentAssertion = (span: TraceSpan, depth: number) => void
1399+
1400+
/**
1401+
* The whole-trace content check, applied to each projected span as soon as its own content is
1402+
* final. Called in projection order (pre-order, a parent before its children), it walks exactly
1403+
* what one walk of the finished trace would, so an over-budget trace fails at the span that
1404+
* crosses the budget instead of after the whole trace was projected and then discarded.
1405+
*/
1406+
function createSpanContentAssertion(
1407+
traceSpans: readonly TraceSpan[],
13531408
context: PlaintextInvariantContext
1354-
): void {
1409+
): SpanContentAssertion {
1410+
const structureState: BoundedTraceStructureState = { nodes: 0, truncated: false }
13551411
const contentState: TraversalState = { nodes: 0, ancestors: new WeakSet<object>() }
1356-
visitTraceSpansContent(traceSpans, (value) => assertNoPlaintext(value, context, contentState))
1412+
assertTraceStructureArrayFits(traceSpans, structureState)
1413+
const visit = (value: unknown) => assertNoPlaintext(value, context, contentState)
1414+
return (span, depth) => visitTraceSpanOwnContent(span, visit, structureState, depth)
13571415
}
13581416

13591417
function collectPostTransformLargeValues(
@@ -1577,10 +1635,10 @@ export async function projectTraceSpansForSecrets(
15771635
const projected: TraceSpan[] = []
15781636
const state: BoundedTraceStructureState = { nodes: 0, truncated: false }
15791637
assertTraceStructureArrayFits(traceSpans, state)
1638+
const assertContentIsSafe = createSpanContentAssertion(traceSpans, context)
15801639
for (const span of traceSpans) {
1581-
projected.push(await sanitizeTraceSpan(span, context, 0, state))
1640+
projected.push(await sanitizeTraceSpan(span, context, 0, state, assertContentIsSafe))
15821641
}
1583-
assertTraceSpansContentIsSafe(projected, context)
15841642
return projected
15851643
} catch (error) {
15861644
logger.warn('Trace secret projection failed; retaining structural spans only', {

0 commit comments

Comments
 (0)