Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
32 changes: 30 additions & 2 deletions apps/sim/lib/logs/execution/logger.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ import type { SerializableExecutionState } from '@/executor/execution/types'
afterAll(resetDbChainMock)

/** Flat logger whose withMetadata() children share one spy set, so log level is assertable. */
const { mockLogger } = vi.hoisted(() => {
const { mockLogger, statsLogErrorMock } = vi.hoisted(() => {
const mockLogger: Record<string, ReturnType<typeof vi.fn>> = {
info: vi.fn(),
warn: vi.fn(),
Expand All @@ -27,7 +27,7 @@ const { mockLogger } = vi.hoisted(() => {
}
mockLogger.child = vi.fn(() => mockLogger)
mockLogger.withMetadata = vi.fn(() => mockLogger)
return { mockLogger }
return { mockLogger, statsLogErrorMock: mockLogger.error }
})

vi.mock('@sim/logger', () => ({
Expand Down Expand Up @@ -1230,4 +1230,32 @@ describe('recordExecutionUsage boundary-delta reconciliation', () => {
// The ledger INSERT participates in the locked transaction.
expect(vi.mocked(recordUsage).mock.calls[0][0]).toHaveProperty('tx')
})

test('reports the driver cause and SQLSTATE when the ledger write fails', async () => {
const driver = Object.assign(new Error('cannot execute INSERT in a read-only transaction'), {
code: '25006',
})
vi.mocked(recordUsage).mockRejectedValueOnce(
new Error('Failed query: insert into "usage_log"\nparams: user-1', { cause: driver })
)

await run(
costSummary({
models: {
'gpt-4o': { input: 0, output: 0, total: 1, tokens: { input: 0, output: 0, total: 0 } },
},
}),
[]
)

expect(statsLogErrorMock).toHaveBeenCalledWith(
'Failed to record execution usage to usage_log ledger; charge may be unbilled',
expect.objectContaining({
cause: expect.objectContaining({
code: '25006',
message: 'cannot execute INSERT in a read-only transaction',
}),
})
)
})
})
4 changes: 2 additions & 2 deletions apps/sim/lib/logs/execution/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ import {
workspace,
} from '@sim/db/schema'
import { createLogger } from '@sim/logger'
import { getErrorMessage } from '@sim/utils/errors'
import { describeError, getErrorMessage } from '@sim/utils/errors'
import { generateId } from '@sim/utils/id'
import { and, eq, inArray, sql } from 'drizzle-orm'
import { checkUsageStatus as checkResolvedUsageStatus } from '@/lib/billing/calculations/usage-monitor'
Expand Down Expand Up @@ -1768,7 +1768,7 @@ export class ExecutionLogger implements IExecutionLoggerService {
statsLog.error(
'Failed to record execution usage to usage_log ledger; charge may be unbilled',
{
error,
cause: describeError(error),
actorUserId,
costSummary,
}
Expand Down
91 changes: 90 additions & 1 deletion apps/sim/lib/logs/execution/trace-secret-projection.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,19 @@
import { createHash } from 'node:crypto'
import { beforeEach, describe, expect, it, vi } from 'vitest'

const { materializeLargeValueRefMock, storeLargeValueMock } = vi.hoisted(() => ({
const { materializeLargeValueRefMock, storeLargeValueMock, warnMock } = vi.hoisted(() => ({
materializeLargeValueRefMock: vi.fn(),
storeLargeValueMock: vi.fn(),
warnMock: vi.fn(),
}))

vi.mock('@sim/logger', () => ({
createLogger: () => ({
debug: vi.fn(),
info: vi.fn(),
warn: warnMock,
error: vi.fn(),
}),
}))

vi.mock('@/lib/execution/payloads/store', () => ({
Expand All @@ -24,6 +34,8 @@ import {
ResolvedSecretTraceRegistry,
} from '@/executor/utils/resolved-secret-trace-registry'

const MAX_CONTENT_NODES = 100_000

const STORE = {
workspaceId: 'workspace-1',
workflowId: 'workflow-1',
Expand Down Expand Up @@ -438,6 +450,25 @@ describe('projectTraceSpansForSecrets', () => {
expect(source[0].output).toEqual({ apiKey: '[REDACTED]' })
})

it('names the invariant that forced the structural fallback', async () => {
const source = [createSpan({ output: { apiKey: '[REDACTED]' } })]

await enforceTraceSpanSecretInvariant(source, {
registry: createRegistry([{ plaintext: 'E', replacement: '{{X}}' }]),
store: STORE,
})

expect(warnMock).toHaveBeenCalledWith(
'Trace secret invariant failed; retaining structural spans only',
{
failure: {
name: 'TraceSecretProjectionError',
reason: expect.any(String),
},
}
)
})

it('fails the final invariant closed when provenance is incomplete', async () => {
const source = [createSpan({ output: { value: 'ordinary' } })]

Expand Down Expand Up @@ -1149,6 +1180,64 @@ describe('projectTraceSpansForSecrets', () => {
expect(result[0].output).toEqual({ token: '{{API_SECRET}}' })
})

it('names the invariant that forced content to be omitted', async () => {
const output: Record<string, unknown> = { token: 'top-secret' }
output.self = output

const [result] = await projectTraceSpansForSecrets([createSpan({ output })], {
registry: createRegistry([{ plaintext: 'top-secret', replacement: '{{API_SECRET}}' }]),
store: STORE,
})

expect(result).not.toHaveProperty('output')
expect(warnMock).toHaveBeenCalledWith('Omitting trace content that could not be sanitized', {
failure: {
name: 'TraceSecretProjectionError',
reason: 'Trace content could not be sanitized',
},
})
})

it('withholds the message of a failure raised outside the projection module', async () => {
const descriptorSpy = vi.spyOn(Object, 'getOwnPropertyDescriptor').mockImplementation(() => {
throw new SyntaxError('Unexpected token in "sk-live-top-secret"')
})

try {
await projectTraceSpansForSecrets([createSpan({ output: { token: 'top-secret' } })], {
registry: createRegistry([{ plaintext: 'top-secret', replacement: '{{API_SECRET}}' }]),
store: STORE,
})
} finally {
descriptorSpy.mockRestore()
}

expect(warnMock).toHaveBeenCalledWith('Omitting trace content that could not be sanitized', {
failure: { name: 'SyntaxError' },
})
})

it('names the invariant that forced the whole-tree structural fallback', async () => {
const source = Array(MAX_CONTENT_NODES + 1).fill(
createSpan({ output: { token: 'top-secret' } })
)

await projectTraceSpansForSecrets(source, {
registry: createRegistry([{ plaintext: 'top-secret', replacement: '{{API_SECRET}}' }]),
store: STORE,
})

expect(warnMock).toHaveBeenCalledWith(
'Trace secret projection failed; retaining structural spans only',
{
failure: {
name: 'TraceSecretProjectionError',
reason: 'Trace structure array exceeds the projection limit',
},
}
)
})

it('uses bounded structural fallback when matcher construction fails', async () => {
let source = createSpan({ id: 'depth-150', output: { secret: 'raw' } })
for (let depth = 149; depth >= 0; depth -= 1) {
Expand Down
40 changes: 32 additions & 8 deletions apps/sim/lib/logs/execution/trace-secret-projection.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
import { createLogger } from '@sim/logger'
import { toError } from '@sim/utils/errors'
import { isPlainRecord, omit } from '@sim/utils/object'
import {
isLargeArrayManifest,
Expand Down Expand Up @@ -128,6 +129,21 @@ class TraceSecretProjectionError extends Error {
}
}

/**
* Diagnostic payload for a projection fallback.
*
* Every {@link TraceSecretProjectionError} message is a fixed literal describing
* which invariant fired, so it is safe to log. Any other failure originates
* outside this module and may embed trace content (a JSON parse error quotes the
* text it choked on), so only its name is reported.
*/
function describeProjectionFailure(error: unknown): { name: string; reason?: string } {
return {
name: toError(error).name,
...(error instanceof TraceSecretProjectionError ? { reason: error.message } : {}),
}
}

function createProjectionContext(
matcher: ResolvedSecretMatcher,
store: LargeValueStoreContext,
Expand Down Expand Up @@ -786,8 +802,10 @@ async function sanitizeContentField(
): Promise<unknown | typeof OMIT> {
try {
return await sanitizeMaterializedValue(value, context)
} catch {
logger.warn('Omitting trace content that could not be sanitized')
} catch (error) {
logger.warn('Omitting trace content that could not be sanitized', {
failure: describeProjectionFailure(error),
})
return OMIT
}
}
Expand Down Expand Up @@ -1182,8 +1200,10 @@ function projectBoundedTraceSpans(
function structuralOnlyTraceSpans(traceSpans: TraceSpan[]): TraceSpan[] {
try {
return projectBoundedTraceSpans(traceSpans, structuralOnlySpan)
} catch {
logger.warn('Trace structure could not be safely traversed; omitting projected spans')
} catch (error) {
logger.warn('Trace structure could not be safely traversed; omitting projected spans', {
failure: describeProjectionFailure(error),
})
return []
}
}
Expand Down Expand Up @@ -1522,8 +1542,10 @@ export async function enforceTraceSpanSecretInvariant(

await assertPostTransformTraceSpansAreSafe(traceSpans, matcher, options.store)
return traceSpans
} catch {
logger.warn('Trace secret invariant failed; retaining structural spans only')
} catch (error) {
logger.warn('Trace secret invariant failed; retaining structural spans only', {
failure: describeProjectionFailure(error),
})
return structuralOnlyTraceSpans(traceSpans)
}
}
Expand Down Expand Up @@ -1560,8 +1582,10 @@ export async function projectTraceSpansForSecrets(
}
assertTraceSpansContentIsSafe(projected, context)
return projected
} catch {
logger.warn('Trace secret projection failed; retaining structural spans only')
} catch (error) {
logger.warn('Trace secret projection failed; retaining structural spans only', {
failure: describeProjectionFailure(error),
})
return structuralOnlyTraceSpans(traceSpans)
}
}
34 changes: 34 additions & 0 deletions apps/sim/lib/uploads/contexts/workspace/fetch-external-url.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,13 @@
* the module graph is fresh or reused.
*/
import { afterAll, beforeEach, describe, expect, it, vi } from 'vitest'

const { warnMock } = vi.hoisted(() => ({ warnMock: vi.fn() }))

vi.mock('@sim/logger', () => ({
createLogger: () => ({ debug: vi.fn(), info: vi.fn(), warn: warnMock, error: vi.fn() }),
}))

import * as inputValidation from '@/lib/core/security/input-validation.server'
import {
ExternalUrlValidationError,
Expand Down Expand Up @@ -200,6 +207,33 @@ describe('fetchExternalUrlToWorkspace', () => {
expect(result.savedWorkspaceFile).toBeUndefined()
})

it('logs the driver cause and SQLSTATE behind a swallowed workspace save error', async () => {
const driver = Object.assign(
new Error('cannot execute SELECT FOR UPDATE in a read-only transaction'),
{ code: '25006' }
)
secureFetchWithPinnedIPSpy.mockResolvedValue(makeResponse('bytes', 'text/plain'))
uploadWorkspaceFileSpy.mockRejectedValueOnce(
new Error('Failed to upload file: storage accounting failed', { cause: driver })
)

await fetchExternalUrlToWorkspace({
url: 'https://example.com/file.txt',
userId: 'user-1',
workspaceId: 'workspace-1',
})

expect(warnMock).toHaveBeenCalledWith(
'Failed to save fetched URL to workspace storage',
expect.objectContaining({
cause: expect.objectContaining({
code: '25006',
message: 'cannot execute SELECT FOR UPDATE in a read-only transaction',
}),
})
)
})

it('forwards custom headers to the fetch', async () => {
secureFetchWithPinnedIPSpy.mockResolvedValue(makeResponse('bytes', 'text/plain'))

Expand Down
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
import type { Buffer } from 'buffer'
import path from 'path'
import { createLogger } from '@sim/logger'
import { describeError } from '@sim/utils/errors'
import {
secureFetchWithPinnedIP,
validateUrlWithDNS,
Expand Down Expand Up @@ -134,7 +135,7 @@ export async function fetchExternalUrlToWorkspace(
logger.warn('Failed to save fetched URL to workspace storage', {
workspaceId,
filename,
saveError,
cause: describeError(saveError),
})
}
} else if (permission === null) {
Expand Down
22 changes: 15 additions & 7 deletions apps/sim/lib/uploads/contexts/workspace/workspace-file-manager.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,12 @@ import { randomBytes } from 'crypto'
import { db } from '@sim/db'
import { workspaceFiles } from '@sim/db/schema'
import { createLogger } from '@sim/logger'
import { getErrorMessage, getPostgresConstraintName, getPostgresErrorCode } from '@sim/utils/errors'
import {
describeError,
getErrorMessage,
getPostgresConstraintName,
getPostgresErrorCode,
} from '@sim/utils/errors'
import { generateShortId } from '@sim/utils/id'
import { and, eq, isNotNull, isNull, or, sql } from 'drizzle-orm'
import type { ShareRecord } from '@/lib/api/contracts/public-shares'
Expand Down Expand Up @@ -446,15 +451,18 @@ export async function uploadWorkspaceFile(
)
continue
}
logger.error(`Failed to upload workspace file ${fileName}:`, error)
throw new Error(`Failed to upload file: ${getErrorMessage(error, 'Unknown error')}`)
logger.error(`Failed to upload workspace file ${fileName}:`, {
cause: describeError(error),
})
throw new Error(`Failed to upload file: ${getErrorMessage(error, 'Unknown error')}`, {
cause: error,
})
}
}

logger.error(
`Failed to upload workspace file after ${MAX_UPLOAD_UNIQUE_RETRIES} attempts`,
lastError
)
logger.error(`Failed to upload workspace file after ${MAX_UPLOAD_UNIQUE_RETRIES} attempts`, {
cause: describeError(lastError),
})
throw new FileConflictError(fileName)
}

Expand Down
Loading