diff --git a/apps/sim/lib/logs/execution/logger.test.ts b/apps/sim/lib/logs/execution/logger.test.ts index 6f7ea251622..714753bdbbc 100644 --- a/apps/sim/lib/logs/execution/logger.test.ts +++ b/apps/sim/lib/logs/execution/logger.test.ts @@ -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> = { info: vi.fn(), warn: vi.fn(), @@ -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', () => ({ @@ -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', + }), + }) + ) + }) }) diff --git a/apps/sim/lib/logs/execution/logger.ts b/apps/sim/lib/logs/execution/logger.ts index ef9cf67a9df..0bde3786d2b 100644 --- a/apps/sim/lib/logs/execution/logger.ts +++ b/apps/sim/lib/logs/execution/logger.ts @@ -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' @@ -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, } 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 82d09bc259e..ccc8969e2ba 100644 --- a/apps/sim/lib/logs/execution/trace-secret-projection.test.ts +++ b/apps/sim/lib/logs/execution/trace-secret-projection.test.ts @@ -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', () => ({ @@ -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', @@ -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' } })] @@ -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 = { 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) { diff --git a/apps/sim/lib/logs/execution/trace-secret-projection.ts b/apps/sim/lib/logs/execution/trace-secret-projection.ts index cbd7bedf8db..7ff7501739a 100644 --- a/apps/sim/lib/logs/execution/trace-secret-projection.ts +++ b/apps/sim/lib/logs/execution/trace-secret-projection.ts @@ -1,4 +1,5 @@ import { createLogger } from '@sim/logger' +import { toError } from '@sim/utils/errors' import { isPlainRecord, omit } from '@sim/utils/object' import { isLargeArrayManifest, @@ -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, @@ -786,8 +802,10 @@ async function sanitizeContentField( ): Promise { 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 } } @@ -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 [] } } @@ -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) } } @@ -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) } } diff --git a/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.test.ts b/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.test.ts index 6348ef9d240..d00eceb0fae 100644 --- a/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.test.ts +++ b/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.test.ts @@ -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, @@ -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')) diff --git a/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.ts b/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.ts index fa942319876..3a0c495f59d 100644 --- a/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.ts +++ b/apps/sim/lib/uploads/contexts/workspace/fetch-external-url.ts @@ -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, @@ -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) { diff --git a/apps/sim/lib/uploads/contexts/workspace/workspace-file-manager.ts b/apps/sim/lib/uploads/contexts/workspace/workspace-file-manager.ts index fee6e8e08b0..4bae36791dc 100644 --- a/apps/sim/lib/uploads/contexts/workspace/workspace-file-manager.ts +++ b/apps/sim/lib/uploads/contexts/workspace/workspace-file-manager.ts @@ -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' @@ -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) } diff --git a/apps/sim/lib/uploads/contexts/workspace/workspace-file-storage-accounting.test.ts b/apps/sim/lib/uploads/contexts/workspace/workspace-file-storage-accounting.test.ts index cb0cf163b1e..23c2d3b6b37 100644 --- a/apps/sim/lib/uploads/contexts/workspace/workspace-file-storage-accounting.test.ts +++ b/apps/sim/lib/uploads/contexts/workspace/workspace-file-storage-accounting.test.ts @@ -2,6 +2,7 @@ * @vitest-environment node */ import { dbChainMockFns, resetDbChainMock } from '@sim/testing' +import { describeError } from '@sim/utils/errors' import { beforeEach, describe, expect, it, vi } from 'vitest' const { @@ -159,6 +160,32 @@ describe('workspace file metadata and storage accounting', () => { ) }) + it('preserves the driver cause so the SQLSTATE survives the upload wrapper', async () => { + const driver = Object.assign( + new Error('cannot execute SELECT FOR UPDATE in a read-only transaction'), + { code: '25006' } + ) + dbChainMockFns.returning.mockResolvedValueOnce([FILE_ROW]) + mockIncrementStorageUsageForBillingContextInTx.mockRejectedValueOnce( + new Error( + 'Failed query: select "storage_used_bytes" from "workspace" where id = $1 limit $2 for update\nparams: ws-1,1', + { cause: driver } + ) + ) + + const thrown = await uploadWorkspaceFile( + FILE_ROW.workspaceId, + FILE_ROW.userId, + Buffer.from('hello'), + FILE_ROW.originalName, + FILE_ROW.contentType + ).catch((error: unknown) => error) + + const described = describeError(thrown) + expect(described.code).toBe('25006') + expect(described.message).toBe('cannot execute SELECT FOR UPDATE in a read-only transaction') + }) + it('keeps an ordinary workspace upload on the legacy untracked path', async () => { dbChainMockFns.returning.mockResolvedValueOnce([FILE_ROW]) diff --git a/packages/utils/src/errors.test.ts b/packages/utils/src/errors.test.ts index 736264e051f..263bd468756 100644 --- a/packages/utils/src/errors.test.ts +++ b/packages/utils/src/errors.test.ts @@ -102,6 +102,30 @@ describe('describeError', () => { ]) }) + it('redacts driver-appended bound parameter values from every reported message', () => { + const driver = Object.assign( + new Error('cannot execute SELECT FOR UPDATE in a read-only transaction'), + { + code: '25006', + } + ) + const wrapped = new Error( + 'Failed query: select "storage_used_bytes" from "workspace" where id = $1 limit $2 for update\nparams: ws-secret-id,1', + { cause: driver } + ) + const described = describeError(wrapped) + expect(described.code).toBe('25006') + expect(described.causeChain?.[0]).toBe( + 'Error: Failed query: select "storage_used_bytes" from "workspace" where id = $1 limit $2 for update\nparams: [redacted]' + ) + expect(JSON.stringify(described)).not.toContain('ws-secret-id') + }) + + it('redacts bound parameter values from an unwrapped driver error message', () => { + const described = describeError(new Error('Failed query: select 1\nparams: ws-secret-id')) + expect(described.message).toBe('Failed query: select 1\nparams: [redacted]') + }) + it('always returns the cause for unclassified errors (AbortError)', () => { const aborted = Object.assign(new Error('The operation was aborted'), { name: 'AbortError' }) expect(describeError(aborted)).toEqual({ diff --git a/packages/utils/src/errors.ts b/packages/utils/src/errors.ts index f3f4a45deda..7261f5e51cc 100644 --- a/packages/utils/src/errors.ts +++ b/packages/utils/src/errors.ts @@ -60,6 +60,10 @@ export interface DescribedError { * * Loggers do not serialize the non-enumerable `Error.prototype.cause`, so pass * the result as an explicit structured field rather than the raw error. + * + * Bound parameter values are stripped from every reported message: Drizzle's + * `DrizzleQueryError` appends `\nparams: ` to the failing SQL, and those + * values are user data that must never reach logs. */ export function describeError(error: unknown): DescribedError { const chain: Error[] = [] @@ -73,7 +77,7 @@ export function describeError(error: unknown): DescribedError { if (chain.length === 0) { const normalized = toError(error) - return { name: normalized.name, message: normalized.message } + return { name: normalized.name, message: redactBoundParameters(normalized.message) } } const deepest = chain[chain.length - 1] as Error & Record @@ -85,14 +89,22 @@ export function describeError(error: unknown): DescribedError { return { name: deepest.name, - message: deepest.message, + message: redactBoundParameters(deepest.message), ...(code ? { code } : {}), ...(errno ? { errno } : {}), ...(syscall ? { syscall } : {}), - ...(chain.length > 1 ? { causeChain: chain.map((e) => `${e.name}: ${e.message}`) } : {}), + ...(chain.length > 1 + ? { causeChain: chain.map((e) => `${e.name}: ${redactBoundParameters(e.message)}`) } + : {}), } } +/** Replaces a driver-appended `params: ` tail with a redaction marker. */ +function redactBoundParameters(message: string): string { + const index = message.indexOf('\nparams:') + return index === -1 ? message : `${message.slice(0, index)}\nparams: [redacted]` +} + /** * First link in the `.cause` chain (including `error` itself) matching * `predicate`. Lets a caller recover a specific wrapped error class instead of