Skip to content

Commit ff64389

Browse files
authored
fix(logs): keep run provenance when compaction drops the execution state (#6528)
* fix(logs): keep run provenance when compaction drops the execution state Oversized-payload compaction drops executionState wholesale but keeps secretProjectionVersion, so the display projection saw a contract-marked row it could not verify and returned structural-only spans — blanking every input and output in the trace. Store the provenance top-level so it survives compaction, omit it from both display projections (it carries encrypted secret values and their names), and let rows truncated before this shipped keep the spans they were already projected with at write time. * improvement(logs): type the new test helpers instead of using any
1 parent 5478a69 commit ff64389

5 files changed

Lines changed: 359 additions & 12 deletions

File tree

apps/sim/lib/logs/execution/logger.test.ts

Lines changed: 182 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import {
55
queueTableRows,
66
resetDbChainMock,
77
} from '@sim/testing'
8+
import { isPlainRecord } from '@sim/utils/object'
89
import { afterAll, beforeEach, describe, expect, test, vi } from 'vitest'
910
import { recordUsage } from '@/lib/billing/core/usage-log'
1011
import { ExecutionLogger } from '@/lib/logs/execution/logger'
@@ -288,6 +289,109 @@ describe('ExecutionLogger', () => {
288289
expect(emitExecutionCompletedEvent).not.toHaveBeenCalled()
289290
})
290291

292+
const EMPTY_STATE = {
293+
blockStates: {},
294+
executedBlocks: [],
295+
blockLogs: [],
296+
decisions: { router: {}, condition: {} },
297+
completedLoops: [],
298+
activeExecutionPath: [],
299+
}
300+
const RUN_PROVENANCE = { version: 1, complete: true, entries: [] }
301+
302+
/**
303+
* Drives a real completion and returns the `execution_data` actually written.
304+
* `redactedState` stands in for the PII pass, which either hands back a
305+
* redacted state or none at all.
306+
*/
307+
async function completeAndReadWrite(params: {
308+
executionState?: SerializableExecutionState
309+
redactedState?: SerializableExecutionState
310+
}) {
311+
const startedAt = new Date('2026-08-11T00:00:00.000Z')
312+
queueTableRows(workflowExecutionLogs, [
313+
{
314+
id: 'log-1',
315+
workflowId: 'workflow-1',
316+
workspaceId: 'workspace-1',
317+
executionId: 'execution-1',
318+
stateSnapshotId: 'snapshot-1',
319+
level: 'info',
320+
status: 'running',
321+
trigger: 'api',
322+
startedAt,
323+
endedAt: null,
324+
totalDurationMs: null,
325+
executionData: {},
326+
createdAt: startedAt,
327+
},
328+
])
329+
dbChainMockFns.returning.mockResolvedValueOnce([
330+
{ id: 'log-1', executionData: {}, startedAt, createdAt: startedAt },
331+
])
332+
const internals = logger as unknown as {
333+
applyPiiRedaction: (workspaceId: string, payload: Record<string, unknown>) => unknown
334+
recordExecutionUsage: () => Promise<number>
335+
}
336+
vi.spyOn(internals, 'applyPiiRedaction').mockImplementation(
337+
async (_workspaceId: string, payload: Record<string, unknown>) =>
338+
Object.hasOwn(params, 'redactedState')
339+
? { ...payload, executionState: params.redactedState }
340+
: payload
341+
)
342+
vi.spyOn(internals, 'recordExecutionUsage').mockResolvedValue(0)
343+
344+
await logger.completeWorkflowExecution({
345+
executionId: 'execution-1',
346+
endedAt: '2026-08-11T00:00:02.000Z',
347+
totalDurationMs: 2000,
348+
costSummary: {
349+
totalCost: 0,
350+
totalInputCost: 0,
351+
totalOutputCost: 0,
352+
totalTokens: 0,
353+
totalPromptTokens: 0,
354+
totalCompletionTokens: 0,
355+
baseExecutionCharge: 0,
356+
models: {},
357+
},
358+
finalOutput: { completed: true },
359+
traceSpans: [],
360+
...(params.executionState ? { executionState: params.executionState } : {}),
361+
})
362+
363+
return dbChainMockFns.set.mock.calls
364+
.map(([values]: [{ executionData?: unknown }]) => values?.executionData)
365+
.find((data): data is Record<string, unknown> => isPlainRecord(data))
366+
}
367+
368+
/**
369+
* The display projection rebuilds its redaction registry from this key.
370+
* Compaction drops `executionState`, so the run provenance has to reach the
371+
* row independently of it or truncated runs render as an empty trace.
372+
*/
373+
test.each([
374+
['redaction preserves the state', EMPTY_STATE],
375+
['redaction drops the state entirely', undefined],
376+
])('lifts run provenance onto the top-level key when %s', async (_case, redactedState) => {
377+
const written = await completeAndReadWrite({
378+
executionState: {
379+
...EMPTY_STATE,
380+
resolvedSecretTraceProvenance: RUN_PROVENANCE,
381+
} as unknown as SerializableExecutionState,
382+
redactedState: redactedState as SerializableExecutionState | undefined,
383+
})
384+
385+
expect(written?.resolvedSecretTraceProvenance).toEqual(RUN_PROVENANCE)
386+
})
387+
388+
test('omits the provenance key when the run carried none', async () => {
389+
const written = await completeAndReadWrite({})
390+
391+
expect(written).toBeDefined()
392+
expect(written).not.toHaveProperty('resolvedSecretTraceProvenance')
393+
})
394+
291395
test('preserves correlation and diagnostics when execution completes', () => {
292396
const loggerInstance = new ExecutionLogger() as any
293397

@@ -628,6 +732,84 @@ describe('ExecutionLogger', () => {
628732
expect(compacted.traceSpans?.[0]?.toolCalls?.[0]).not.toHaveProperty('output')
629733
expect(compacted.traceSpans?.[0]?.toolCalls?.[0]).not.toHaveProperty('error')
630734
})
735+
736+
const PROVENANCE = { version: 1, complete: true, entries: [] } as const
737+
738+
function buildSpans(spanCount: number, ioBytes: number) {
739+
const payload = 'x'.repeat(ioBytes)
740+
return Array.from({ length: spanCount }, (_unused, index) => ({
741+
id: `span-${index}`,
742+
name: `Block ${index}`,
743+
type: 'function',
744+
duration: 1,
745+
startTime: '2025-01-01T00:00:00.000Z',
746+
endTime: '2025-01-01T00:00:01.000Z',
747+
status: 'success' as const,
748+
output: { data: payload },
749+
}))
750+
}
751+
752+
function compactWithProvenance(traceSpans: unknown[], finalOutput: unknown) {
753+
const loggerInstance = new ExecutionLogger() as unknown as {
754+
compactExecutionDataForStorage: (
755+
data: Record<string, unknown>,
756+
executionId: string
757+
) => Record<string, unknown>
758+
}
759+
return loggerInstance.compactExecutionDataForStorage(
760+
{
761+
secretProjectionVersion: SECRET_PROJECTION_VERSION,
762+
resolvedSecretTraceProvenance: PROVENANCE,
763+
hasTraceSpans: true,
764+
traceSpanCount: traceSpans.length,
765+
finalOutput,
766+
executionState: {
767+
blockStates: {},
768+
executedBlocks: [],
769+
blockLogs: [],
770+
decisions: { router: {}, condition: {} },
771+
completedLoops: [],
772+
activeExecutionPath: [],
773+
resolvedSecretTraceProvenance: PROVENANCE,
774+
},
775+
traceSpans,
776+
},
777+
'execution-provenance'
778+
)
779+
}
780+
781+
test('preserves run provenance through the summarized compaction tier', () => {
782+
// One oversized value: summarization alone brings the row under the cap.
783+
const compacted = compactWithProvenance(buildSpans(1, 4 * 1024 * 1024), {
784+
data: 'x'.repeat(4 * 1024 * 1024),
785+
})
786+
787+
expect(compacted.executionDataTruncated).toBe(true)
788+
expect(compacted.executionDataTruncationReason).toContain('were summarized')
789+
expect(compacted.executionState).toBeUndefined()
790+
expect(compacted.resolvedSecretTraceProvenance).toEqual(PROVENANCE)
791+
})
792+
793+
test('drops run provenance from the metadata-only tier, which stores no spans', () => {
794+
// That tier keeps no traceSpans, so provenance there buys nothing and
795+
// would put an unbounded value in the last-resort size floor.
796+
const compacted = compactWithProvenance(buildSpans(20_000, 8), {})
797+
798+
expect(compacted.executionDataTruncationReason).toContain('only execution metadata')
799+
expect(compacted.traceSpans).toBeUndefined()
800+
expect(compacted.resolvedSecretTraceProvenance).toBeUndefined()
801+
})
802+
803+
test('preserves run provenance through the minimal compaction tier', () => {
804+
// Many spans whose IO each sits under MAX_TRACE_IO_BYTES survive
805+
// summarization, so only the IO-stripping minimal tier fits the cap.
806+
const compacted = compactWithProvenance(buildSpans(1200, 4 * 1024), {})
807+
808+
expect(compacted.executionDataTruncated).toBe(true)
809+
expect(compacted.executionDataTruncationReason).toContain('details were omitted')
810+
expect(compacted.executionState).toBeUndefined()
811+
expect(compacted.resolvedSecretTraceProvenance).toEqual(PROVENANCE)
812+
})
631813
})
632814

633815
describe('file extraction', () => {

apps/sim/lib/logs/execution/logger.ts

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -449,6 +449,9 @@ export class ExecutionLogger implements IExecutionLoggerService {
449449

450450
const minimal: ExecutionData = {
451451
secretProjectionVersion: SECRET_PROJECTION_VERSION,
452+
...(executionData.resolvedSecretTraceProvenance !== undefined
453+
? { resolvedSecretTraceProvenance: executionData.resolvedSecretTraceProvenance }
454+
: {}),
452455
...(executionData.environment ? { environment: executionData.environment } : {}),
453456
...(executionData.trigger ? { trigger: executionData.trigger } : {}),
454457
...(executionData.billingAttribution
@@ -1102,8 +1105,18 @@ export class ExecutionLogger implements IExecutionLoggerService {
11021105
builtExecutionData.executionState
11031106
)
11041107

1108+
/**
1109+
* Duplicated top-level so the display projection can still rebuild its
1110+
* registry after compaction drops `executionState`. Read from the
1111+
* pre-redaction state: `preservePrivateExecutionStateMetadata` copies the
1112+
* provenance across verbatim, and this one also survives redaction
1113+
* producing no state at all.
1114+
*/
1115+
const runProvenance = builtExecutionData.executionState?.resolvedSecretTraceProvenance
1116+
11051117
const cleanExecutionData: ExecutionData = {
11061118
...builtExecutionData,
1119+
...(runProvenance !== undefined ? { resolvedSecretTraceProvenance: runProvenance } : {}),
11071120
traceSpans: copyTraceSpansWithoutCosts(preparedTraceSpans),
11081121
finalOutput: pii.finalOutput as BlockOutputData,
11091122
...(pii.workflowInput !== undefined ? { workflowInput: pii.workflowInput } : {}),

apps/sim/lib/logs/execution/trace-store.test.ts

Lines changed: 87 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@ import {
2222
externalizeExecutionData,
2323
materializeExecutionData,
2424
projectExecutionDataForDisplay,
25+
RESOLVED_SECRET_PROVENANCE_KEY,
2526
SECRET_PROJECTION_VERSION,
2627
TRACE_STORE_REF_KEY,
2728
} from '@/lib/logs/execution/trace-store'
@@ -284,3 +285,89 @@ describe('projectExecutionDataForDisplay', () => {
284285
expect(displayData).not.toHaveProperty('traceSpans')
285286
})
286287
})
288+
289+
describe('projectExecutionDataForDisplay provenance handling', () => {
290+
const PROVENANCE = { version: 1, complete: true, entries: [] } as const
291+
292+
/** A truncated row: spans and markers survive, `executionState` does not. */
293+
function truncatedRow(overrides: Record<string, unknown> = {}) {
294+
return {
295+
secretProjectionVersion: SECRET_PROJECTION_VERSION,
296+
executionDataTruncated: true,
297+
finalOutput: { result: 'unknown-secret' },
298+
traceSpans: [
299+
{
300+
id: 'span-1',
301+
name: 'activeEmails',
302+
type: 'function',
303+
duration: 16,
304+
startTime: '2026-08-11T00:38:53.000Z',
305+
endTime: '2026-08-11T00:38:53.016Z',
306+
status: 'error',
307+
input: { code: 'const activeEmails = rows.length' },
308+
output: { error: 'nested large values' },
309+
},
310+
],
311+
...overrides,
312+
}
313+
}
314+
315+
/** First span of a projected display payload. */
316+
function firstSpan(displayData: Record<string, unknown>): Record<string, unknown> {
317+
const [span] = displayData.traceSpans as Record<string, unknown>[]
318+
return span
319+
}
320+
321+
it.each([
322+
['a contract row', () => truncatedRow({ [RESOLVED_SECRET_PROVENANCE_KEY]: PROVENANCE })],
323+
['a legacy row', () => ({ [RESOLVED_SECRET_PROVENANCE_KEY]: PROVENANCE, finalOutput: {} })],
324+
])('never returns the resolved-secret provenance to the client from %s', async (_case, row) => {
325+
const displayData = await projectExecutionDataForDisplay(row(), CONTEXT)
326+
327+
expect(displayData).not.toHaveProperty(RESOLVED_SECRET_PROVENANCE_KEY)
328+
})
329+
330+
it('rebuilds the registry from the top-level key alone', async () => {
331+
const { secretProjectionVersion: _marker, ...withoutMarker } = truncatedRow()
332+
333+
const displayData = await projectExecutionDataForDisplay(
334+
{ ...withoutMarker, [RESOLVED_SECRET_PROVENANCE_KEY]: PROVENANCE },
335+
CONTEXT
336+
)
337+
338+
expect(displayData.finalOutput).toEqual({ result: 'unknown-secret' })
339+
expect(firstSpan(displayData)).toHaveProperty('input')
340+
})
341+
342+
it('keeps write-time-projected spans on a truncated row with no provenance', async () => {
343+
const displayData = await projectExecutionDataForDisplay(truncatedRow(), CONTEXT)
344+
345+
expect(firstSpan(displayData)).toMatchObject({
346+
input: { code: 'const activeEmails = rows.length' },
347+
output: { error: 'nested large values' },
348+
})
349+
// The envelope has no write-time guarantee, so it still fails closed.
350+
expect(displayData).not.toHaveProperty('finalOutput')
351+
})
352+
353+
it.each([
354+
['the row was never truncated', { executionDataTruncated: undefined }],
355+
['the provenance key is present but null', { [RESOLVED_SECRET_PROVENANCE_KEY]: null }],
356+
['the provenance is malformed', { [RESOLVED_SECRET_PROVENANCE_KEY]: { version: 99 } }],
357+
])('fails closed when %s', async (_case, overrides) => {
358+
const displayData = await projectExecutionDataForDisplay(truncatedRow(overrides), CONTEXT)
359+
360+
const span = firstSpan(displayData)
361+
expect(span).not.toHaveProperty('input')
362+
expect(span).not.toHaveProperty('output')
363+
})
364+
365+
it('leaves an empty span array intact', async () => {
366+
const displayData = await projectExecutionDataForDisplay(
367+
truncatedRow({ traceSpans: [] }),
368+
CONTEXT
369+
)
370+
371+
expect(displayData.traceSpans).toEqual([])
372+
})
373+
})

0 commit comments

Comments
 (0)