From 189a0c7c9854240c4a16a0d1ac01e39fba0271ab Mon Sep 17 00:00:00 2001 From: Waleed Latif Date: Thu, 22 Oct 2026 11:56:56 -0700 Subject: [PATCH 1/2] 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. --- .../execution/trace-secret-projection.test.ts | 28 +++++++ .../logs/execution/trace-secret-projection.ts | 78 ++++++++++++++++--- 2 files changed, 96 insertions(+), 10 deletions(-) diff --git a/apps/sim/lib/logs/execution/trace-secret-projection.test.ts b/apps/sim/lib/logs/execution/trace-secret-projection.test.ts index 10ad61b18b0..5cd5e03db9e 100644 --- a/apps/sim/lib/logs/execution/trace-secret-projection.test.ts +++ b/apps/sim/lib/logs/execution/trace-secret-projection.test.ts @@ -340,6 +340,34 @@ describe('projectTraceSpansForSecrets', () => { expect(result[0].output).toEqual({ value: 'prefix {{LONG}} suffix' }) }) + it('lets pending macrotasks run mid-projection and still projects every span', async () => { + const spans = Array.from({ length: 30 }, (_, spanIndex) => + createSpan({ + id: `span-${spanIndex}`, + output: { + rows: Array.from({ length: 400 }, (_, row) => ({ + name: `row ${row}`, + note: 'contains secretval inline', + })), + }, + }) + ) + let macrotaskRan = false + setImmediate(() => { + macrotaskRan = true + }) + + const projected = await projectTraceSpansForSecrets(spans, { + registry: createRegistry([{ plaintext: 'secretval', replacement: '{{SECRET}}' }]), + store: STORE, + }) + + expect(macrotaskRan).toBe(true) + expect(projected[29].output).toEqual({ + rows: expect.arrayContaining([{ name: 'row 399', note: 'contains {{SECRET}} inline' }]), + }) + }) + it('projects a successfully resolved numeric Function result without mutating runtime output', async () => { const runtimeOutput = { result: 12345678, unchanged: 5678 } const source = createSpan({ output: runtimeOutput }) diff --git a/apps/sim/lib/logs/execution/trace-secret-projection.ts b/apps/sim/lib/logs/execution/trace-secret-projection.ts index 7ff7501739a..0365ba3c8cc 100644 --- a/apps/sim/lib/logs/execution/trace-secret-projection.ts +++ b/apps/sim/lib/logs/execution/trace-secret-projection.ts @@ -36,6 +36,7 @@ const MAX_LARGE_VALUES = 1_024 const MAX_LARGE_VALUE_CHAIN_DEPTH = 32 const MAX_LARGE_MANIFEST_CHUNKS = MAX_LARGE_VALUES const MAX_LARGE_MANIFEST_ITEMS = MAX_CONTENT_NODES +const PROJECTION_SLICE_MS = 10 const OMIT = Symbol('omit-trace-content') const LARGE_VALUE_REF_KEYS = new Set([ LARGE_VALUE_REF_MARKER, @@ -167,6 +168,38 @@ function createProjectionContext( } } +let projectionSliceEndsAt = 0 +let projectionTurnScheduled = false +const projectionTurnQueue: Array<() => void> = [] + +/** + * Projection is CPU-bound and its awaits settle as microtasks, which never let the event loop + * service I/O, so without a macrotask yield one large trace — or a page of them projected + * concurrently — holds the whole process until it finishes. + * + * The slice is process-wide and handed to one waiting projection per event-loop turn: releasing + * them together would let each finish its in-flight field before I/O runs again, so a turn would + * grow with concurrency instead of staying at one slice plus one field. + */ +async function yieldWhenSliceExpires(): Promise { + if (performance.now() < projectionSliceEndsAt) return + await new Promise((resolve) => { + projectionTurnQueue.push(resolve) + scheduleProjectionTurn() + }) +} + +function scheduleProjectionTurn(): void { + if (projectionTurnScheduled) return + projectionTurnScheduled = true + setImmediate(() => { + projectionTurnScheduled = false + projectionSliceEndsAt = performance.now() + PROJECTION_SLICE_MS + projectionTurnQueue.shift()?.() + if (projectionTurnQueue.length > 0) scheduleProjectionTurn() + }) +} + function visitNode(state: TraversalState, depth: number): void { state.nodes += 1 if (state.nodes > MAX_CONTENT_NODES) { @@ -800,6 +833,7 @@ async function sanitizeContentField( value: unknown, context: ProjectionContext ): Promise { + await yieldWhenSliceExpires() try { return await sanitizeMaterializedValue(value, context) } catch (error) { @@ -913,7 +947,8 @@ async function sanitizeTraceSpan( span: TraceSpan, context: ProjectionContext, depth: number, - state: BoundedTraceStructureState + state: BoundedTraceStructureState, + assertContentIsSafe: SpanContentAssertion ): Promise { if (!takeTraceStructureNode(state, depth)) { throw new TraceSecretProjectionError('Trace span structure limit exceeded') @@ -954,11 +989,13 @@ async function sanitizeTraceSpan( projected.providerTiming = { ...span.providerTiming, segments } } + assertContentIsSafe(projected, depth) + if (span.children !== undefined) { assertTraceStructureArrayFits(span.children, state) const children: TraceSpan[] = [] for (const child of span.children) { - children.push(await sanitizeTraceSpan(child, context, depth + 1, state)) + children.push(await sanitizeTraceSpan(child, context, depth + 1, state, assertContentIsSafe)) } projected.children = children } @@ -1278,11 +1315,12 @@ function assertNoPlaintext( type TraceContentVisitor = (value: unknown) => void -function visitTraceSpanContent( +/** Visits one span's content, not its children's; `visitTraceSpanContent` descends from here. */ +function visitTraceSpanOwnContent( span: TraceSpan, visit: TraceContentVisitor, structureState: BoundedTraceStructureState, - depth = 0 + depth: number ): void { if (!takeTraceStructureNode(structureState, depth)) { throw new TraceSecretProjectionError('Trace invariant structure limit exceeded') @@ -1335,6 +1373,15 @@ function visitTraceSpanContent( } } assertTraceStructureArrayFits(span.children ?? [], structureState) +} + +function visitTraceSpanContent( + span: TraceSpan, + visit: TraceContentVisitor, + structureState: BoundedTraceStructureState, + depth = 0 +): void { + visitTraceSpanOwnContent(span, visit, structureState, depth) for (const child of span.children ?? []) { visitTraceSpanContent(child, visit, structureState, depth + 1) } @@ -1348,12 +1395,23 @@ function visitTraceSpansContent(traceSpans: TraceSpan[], visit: TraceContentVisi } } -function assertTraceSpansContentIsSafe( - traceSpans: TraceSpan[], +type SpanContentAssertion = (span: TraceSpan, depth: number) => void + +/** + * The whole-trace content check, applied to each projected span as soon as its own content is + * final. Called in projection order (pre-order, a parent before its children), it walks exactly + * what one walk of the finished trace would, so an over-budget trace fails at the span that + * crosses the budget instead of after the whole trace was projected and then discarded. + */ +function createSpanContentAssertion( + traceSpans: readonly TraceSpan[], context: PlaintextInvariantContext -): void { +): SpanContentAssertion { + const structureState: BoundedTraceStructureState = { nodes: 0, truncated: false } const contentState: TraversalState = { nodes: 0, ancestors: new WeakSet() } - visitTraceSpansContent(traceSpans, (value) => assertNoPlaintext(value, context, contentState)) + assertTraceStructureArrayFits(traceSpans, structureState) + const visit = (value: unknown) => assertNoPlaintext(value, context, contentState) + return (span, depth) => visitTraceSpanOwnContent(span, visit, structureState, depth) } function collectPostTransformLargeValues( @@ -1577,10 +1635,10 @@ export async function projectTraceSpansForSecrets( const projected: TraceSpan[] = [] const state: BoundedTraceStructureState = { nodes: 0, truncated: false } assertTraceStructureArrayFits(traceSpans, state) + const assertContentIsSafe = createSpanContentAssertion(traceSpans, context) for (const span of traceSpans) { - projected.push(await sanitizeTraceSpan(span, context, 0, state)) + projected.push(await sanitizeTraceSpan(span, context, 0, state, assertContentIsSafe)) } - assertTraceSpansContentIsSafe(projected, context) return projected } catch (error) { logger.warn('Trace secret projection failed; retaining structural spans only', { From d8a779eeeb29a6605e207a97c14d0f8325c7573a Mon Sep 17 00:00:00 2001 From: Waleed Latif Date: Thu, 22 Oct 2026 12:11:31 -0700 Subject: [PATCH 2/2] fix(logs): check the projection slice at every structure node The slice was only checked per content field, so a trace made of spans, tool calls or provider segments without content never yielded. Check it at every structure node as well, so every unit of projection work is a checkpoint. The regression tests now count event-loop turns during projection on a deterministic clock, so a projection that yields only once at startup and then blocks fails them, and add a structure-only trace. --- .../execution/trace-secret-projection.test.ts | 73 +++++++++++++------ .../logs/execution/trace-secret-projection.ts | 4 + 2 files changed, 55 insertions(+), 22 deletions(-) diff --git a/apps/sim/lib/logs/execution/trace-secret-projection.test.ts b/apps/sim/lib/logs/execution/trace-secret-projection.test.ts index 5cd5e03db9e..ba78a8a90b0 100644 --- a/apps/sim/lib/logs/execution/trace-secret-projection.test.ts +++ b/apps/sim/lib/logs/execution/trace-secret-projection.test.ts @@ -340,32 +340,61 @@ describe('projectTraceSpansForSecrets', () => { expect(result[0].output).toEqual({ value: 'prefix {{LONG}} suffix' }) }) - it('lets pending macrotasks run mid-projection and still projects every span', async () => { - const spans = Array.from({ length: 30 }, (_, spanIndex) => - createSpan({ - id: `span-${spanIndex}`, - output: { - rows: Array.from({ length: 400 }, (_, row) => ({ - name: `row ${row}`, - note: 'contains secretval inline', - })), - }, + /** Never moves backwards across tests: the slice deadline it sets outlives each one. */ + let fakeClockMs = 0 + + /** + * Counts event-loop turns that complete while the projection is in flight, on a clock that + * advances 1ms per read so the slice expires at a fixed rate on any machine. A single yield + * before any work allows one turn — the pending immediate runs, and its successor cannot until + * the projection parks again — so two or more prove it keeps yielding mid-projection. + */ + async function countTurnsDuringProjection(spans: TraceSpan[]) { + fakeClockMs = Math.max(fakeClockMs, performance.now()) + const now = vi.spyOn(performance, 'now').mockImplementation(() => { + fakeClockMs += 1 + return fakeClockMs + }) + let settled = false + let turns = 0 + const tick = () => { + if (settled) return + turns += 1 + setImmediate(tick) + } + setImmediate(tick) + try { + const projected = await projectTraceSpansForSecrets(spans, { + registry: createRegistry([{ plaintext: 'secretval', replacement: '{{SECRET}}' }]), + store: STORE, }) + return { turns, projected } + } finally { + settled = true + now.mockRestore() + } + } + + it('keeps yielding to the event loop throughout a content projection', async () => { + const spans = Array.from({ length: 30 }, (_, index) => + createSpan({ id: `span-${index}`, output: { note: `span ${index} holds secretval` } }) ) - let macrotaskRan = false - setImmediate(() => { - macrotaskRan = true - }) - const projected = await projectTraceSpansForSecrets(spans, { - registry: createRegistry([{ plaintext: 'secretval', replacement: '{{SECRET}}' }]), - store: STORE, - }) + const { turns, projected } = await countTurnsDuringProjection(spans) - expect(macrotaskRan).toBe(true) - expect(projected[29].output).toEqual({ - rows: expect.arrayContaining([{ name: 'row 399', note: 'contains {{SECRET}} inline' }]), - }) + expect(turns).toBeGreaterThanOrEqual(2) + expect(projected[29].output).toEqual({ note: 'span 29 holds {{SECRET}}' }) + }) + + it('keeps yielding to the event loop throughout a structure-only projection', async () => { + const children = Array.from({ length: 50 }, (_, index) => createSpan({ id: `child-${index}` })) + + const { turns, projected } = await countTurnsDuringProjection([ + createSpan({ id: 'root', type: 'workflow', children }), + ]) + + expect(turns).toBeGreaterThanOrEqual(2) + expect(projected[0].children).toHaveLength(50) }) it('projects a successfully resolved numeric Function result without mutating runtime output', async () => { diff --git a/apps/sim/lib/logs/execution/trace-secret-projection.ts b/apps/sim/lib/logs/execution/trace-secret-projection.ts index 0365ba3c8cc..c22f28f8fe0 100644 --- a/apps/sim/lib/logs/execution/trace-secret-projection.ts +++ b/apps/sim/lib/logs/execution/trace-secret-projection.ts @@ -863,6 +863,7 @@ async function sanitizeIterationToolCalls( assertTraceStructureArrayFits(calls, state) const sanitized: IterationToolCall[] = [] for (const call of calls) { + await yieldWhenSliceExpires() if (!takeTraceStructureNode(state, depth)) { throw new TraceSecretProjectionError('Trace tool-call structure limit exceeded') } @@ -885,6 +886,7 @@ async function sanitizeLegacyToolCalls( assertTraceStructureArrayFits(calls, state) const sanitized: ToolCall[] = [] for (const call of calls) { + await yieldWhenSliceExpires() if (!takeTraceStructureNode(state, depth)) { throw new TraceSecretProjectionError('Trace tool-call structure limit exceeded') } @@ -915,6 +917,7 @@ async function sanitizeProviderSegment( state: BoundedTraceStructureState, depth: number ): Promise { + await yieldWhenSliceExpires() if (!takeTraceStructureNode(state, depth)) { throw new TraceSecretProjectionError('Trace provider structure limit exceeded') } @@ -950,6 +953,7 @@ async function sanitizeTraceSpan( state: BoundedTraceStructureState, assertContentIsSafe: SpanContentAssertion ): Promise { + await yieldWhenSliceExpires() if (!takeTraceStructureNode(state, depth)) { throw new TraceSecretProjectionError('Trace span structure limit exceeded') }