From 1beffd3f5f123f8c40c1311134c11e3f256d094d Mon Sep 17 00:00:00 2001 From: Waleed Latif Date: Fri, 2 Oct 2026 01:24:10 -0700 Subject: [PATCH 1/3] fix(logging): name the driver cause and redact bound params in logged errors --- apps/sim/lib/workflows/persistence/utils.ts | 5 +- packages/logger/src/index.test.ts | 77 +++++++++++++++++++++ packages/logger/src/index.ts | 63 ++++++++++++++--- 3 files changed, 136 insertions(+), 9 deletions(-) diff --git a/apps/sim/lib/workflows/persistence/utils.ts b/apps/sim/lib/workflows/persistence/utils.ts index b3d9fc0d979..3d9c6a14ee5 100644 --- a/apps/sim/lib/workflows/persistence/utils.ts +++ b/apps/sim/lib/workflows/persistence/utils.ts @@ -295,7 +295,10 @@ export async function loadDeployedWorkflowState( await resolveWorkspaceId(workflowId, providedWorkspaceId) ) } catch (error) { - logger.error(`Error loading deployed workflow state ${workflowId}:`, error) + // An undeployed workflow is an outcome each caller handles, not a load failure. + if (!(error instanceof NoActiveDeploymentError)) { + logger.error(`Error loading deployed workflow state ${workflowId}:`, error) + } throw error } } diff --git a/packages/logger/src/index.test.ts b/packages/logger/src/index.test.ts index 0c47e916ca7..01659ea343a 100644 --- a/packages/logger/src/index.test.ts +++ b/packages/logger/src/index.test.ts @@ -188,4 +188,81 @@ describe('Logger', () => { expect(parsed.metadataError).toBe(true) }) }) + + describe('wrapped driver errors', () => { + const createEnabledLogger = () => + new Logger('Test', { enabled: true, colorize: false, logLevel: LogLevel.DEBUG }) + + /** Mirrors Drizzle's `DrizzleQueryError`: SQL plus bound values, wrapping the driver error. */ + const queryError = (params: string) => { + const cause = Object.assign(new Error('canceling statement due to statement timeout'), { + name: 'PostgresError', + code: '57014', + }) + const error = new Error( + `Failed query: select "id" from "user_table_rows" where "table_id" = $1 limit $2\nparams: ${params}`, + { cause } + ) + error.name = 'DrizzleQueryError' + return error + } + + test('names the deepest cause and its code on the line', () => { + createEnabledLogger().error('Failed to query rows:', { error: queryError('tbl_1,52') }) + + const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string) + expect(parsed.errorCause).toBe('PostgresError: canceling statement due to statement timeout') + expect(parsed.errorCode).toBe('57014') + }) + + test.each([ + ['an object field', (error: Error) => [{ error }]], + ['a bare argument', (error: Error) => [error]], + ])('keeps bound values out of the message and stack when passed as %s', (_, args) => { + createEnabledLogger().error( + 'Failed to query rows:', + ...args(queryError('alice@example.com,52')) + ) + + const line = consoleErrorSpy.mock.calls[0][0] as string + expect(line).not.toContain('alice@example.com') + const parsed = JSON.parse(line) + expect(parsed.error).toContain('Failed query: select "id"') + expect(parsed.error).toContain('params: [redacted]') + expect(parsed.stack).toContain('params: [redacted]') + expect(parsed.stack).toMatch(/\n\s+at /) + }) + + test('keeps bound values out of an error logged under another key', () => { + createEnabledLogger().error('Insert failed', { dbError: queryError('alice@example.com') }) + + expect(consoleErrorSpy.mock.calls[0][0] as string).not.toContain('alice@example.com') + }) + + test('keeps bound values out of the exported log record', () => { + const emit = vi.fn() + const getLoggerSpy = vi + .spyOn(logs, 'getLogger') + .mockReturnValue({ emit, enabled: () => true }) + try { + createEnabledLogger().error('Failed to query rows:', queryError('alice@example.com')) + + const { attributes } = emit.mock.calls[0][0] + expect(JSON.stringify(attributes)).not.toContain('alice@example.com') + expect(attributes['error.cause']).toBe( + 'PostgresError: canceling statement due to statement timeout' + ) + } finally { + getLoggerSpy.mockRestore() + } + }) + + test('leaves an unwrapped error without cause fields', () => { + createEnabledLogger().error('Request failed', { error: new Error('plain failure') }) + + const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string) + expect(parsed.error).toBe('plain failure') + expect(parsed).not.toHaveProperty('errorCause') + }) + }) }) diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index d13b7f47af0..f8671561ba9 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -5,6 +5,7 @@ * Provides standardized console logging with environment-aware configuration. */ import { logs, SeverityNumber } from '@opentelemetry/api-logs' +import { describeError, redactBoundParameters } from '@sim/utils/errors' import { filterUndefined, isRecordLike } from '@sim/utils/object' import chalk from 'chalk' import { getRequestContext, type RequestContext } from './request-context' @@ -180,6 +181,46 @@ const formatObject = (obj: unknown, isDev: boolean): string => { } } +interface LoggedError { + message: string + stack?: string + /** `"Name: message"` of the deepest `.cause` link, present only when the error wraps another. */ + cause?: string + code?: string +} + +/** + * The fields a log line keeps for an error. + * + * Drizzle's `DrizzleQueryError` appends `\nparams: ` — user data — to + * its message, and the stack repeats the message, so both are redacted. The + * wrapper's message is only the failing SQL; the reason (a statement timeout, a + * constraint violation) lives on the driver error in `.cause`, which no field + * would otherwise carry. + */ +const toLoggedError = (error: Error): LoggedError => { + const message = redactBoundParameters(error.message) + const stack = + error.stack === undefined || message === error.message + ? error.stack + : error.stack.includes(error.message) + ? error.stack.replace(error.message, () => message) + : redactBoundParameters(error.stack) + const described = describeError(error) + return { + message, + stack, + ...(described.causeChain ? { cause: `${described.name}: ${described.message}` } : {}), + ...(described.code ? { code: described.code } : {}), + } +} + +/** Adds an error's cause fields to the entry without displacing caller-supplied values. */ +const assignErrorCause = (entry: Record, logged: LoggedError) => { + if (logged.cause !== undefined && entry.errorCause === undefined) entry.errorCause = logged.cause + if (logged.code !== undefined && entry.errorCode === undefined) entry.errorCode = logged.code +} + /** * Merges caller-supplied log arguments into the structured entry. * @@ -188,23 +229,27 @@ const formatObject = (obj: unknown, isDev: boolean): string => { * is by far the most common call shape, which would otherwise reduce the one * field worth reading to an empty object. Errors nested in an object argument * are therefore unwrapped like a bare `Error` argument. `error` stays a plain - * message string so log queries can group on it; richer diagnostics are opt-in - * via `describeError` from `@sim/utils/errors`. + * message string so log queries can group on it; the primary error's deepest + * cause and its code go in `errorCause` and `errorCode`. */ const mergeArgs = (entry: Record, args: unknown[]): Record => { for (const arg of args) { if (arg === null || arg === undefined) continue if (arg instanceof Error) { - entry.error = arg.message - entry.stack = arg.stack + const logged = toLoggedError(arg) + entry.error = logged.message + entry.stack = logged.stack + assignErrorCause(entry, logged) } else if (typeof arg === 'object') { const source = arg as Record for (const key of Object.keys(source)) { const value = source[key] if (value instanceof Error) { - entry[key] = value.message + const logged = toLoggedError(value) + entry[key] = logged.message if (key === 'error' && entry.stack === undefined) { - entry.stack = value.stack + entry.stack = logged.stack + assignErrorCause(entry, logged) } } else { entry[key] = value @@ -585,8 +630,10 @@ function emitOtelLogRecord( } const firstError = args.find((arg) => arg instanceof Error) as Error | undefined if (firstError) { - attributes['error.message'] = firstError.message - if (firstError.stack) attributes['error.stack'] = firstError.stack + const logged = toLoggedError(firstError) + attributes['error.message'] = logged.message + if (logged.stack) attributes['error.stack'] = logged.stack + if (logged.cause) attributes['error.cause'] = logged.cause } const plainArgs = args.filter((arg) => !(arg instanceof Error)) if (plainArgs.length > 0) { From 0b193db4d83a2a3c5afdffcac1eb0e8209176093 Mon Sep 17 00:00:00 2001 From: Waleed Latif Date: Fri, 2 Oct 2026 01:35:10 -0700 Subject: [PATCH 2/3] fix(logging): redact bound params in colorized, nested, and exported errors --- packages/logger/src/index.test.ts | 65 ++++++++++++--- packages/logger/src/index.ts | 132 +++++++++++++++++------------- 2 files changed, 130 insertions(+), 67 deletions(-) diff --git a/packages/logger/src/index.test.ts b/packages/logger/src/index.test.ts index 01659ea343a..2c61849769b 100644 --- a/packages/logger/src/index.test.ts +++ b/packages/logger/src/index.test.ts @@ -193,20 +193,29 @@ describe('Logger', () => { const createEnabledLogger = () => new Logger('Test', { enabled: true, colorize: false, logLevel: LogLevel.DEBUG }) - /** Mirrors Drizzle's `DrizzleQueryError`: SQL plus bound values, wrapping the driver error. */ + /** + * Mirrors Drizzle's `DrizzleQueryError`: SQL plus bound values in the message, and `query`, + * `params` and `cause` as own enumerable properties, wrapping the driver error. + */ const queryError = (params: string) => { const cause = Object.assign(new Error('canceling statement due to statement timeout'), { name: 'PostgresError', code: '57014', + detail: `Key (email)=(${params}) already exists.`, + }) + const query = 'select "id" from "user_table_rows" where "table_id" = $1 limit $2' + const error = Object.assign(new Error(`Failed query: ${query}\nparams: ${params}`), { + query, + params: params.split(','), + cause, }) - const error = new Error( - `Failed query: select "id" from "user_table_rows" where "table_id" = $1 limit $2\nparams: ${params}`, - { cause } - ) error.name = 'DrizzleQueryError' return error } + const consoleOutput = () => + [...consoleLogSpy.mock.calls, ...consoleErrorSpy.mock.calls].flat().join(' ') + test('names the deepest cause and its code on the line', () => { createEnabledLogger().error('Failed to query rows:', { error: queryError('tbl_1,52') }) @@ -233,19 +242,43 @@ describe('Logger', () => { expect(parsed.stack).toMatch(/\n\s+at /) }) - test('keeps bound values out of an error logged under another key', () => { - createEnabledLogger().error('Insert failed', { dbError: queryError('alice@example.com') }) + test.each([ + ['under another key', (error: Error) => ({ dbError: error })], + ['nested inside metadata', (error: Error) => ({ details: { attempt: 2, error } })], + ])('keeps bound values out of an error logged %s', (_, arg) => { + createEnabledLogger().error('Insert failed', arg(queryError('alice@example.com'))) - expect(consoleErrorSpy.mock.calls[0][0] as string).not.toContain('alice@example.com') + expect(consoleOutput()).not.toContain('alice@example.com') }) - test('keeps bound values out of the exported log record', () => { + test.each([ + ['an object field', (error: Error) => [{ error }]], + ['a bare argument', (error: Error) => [error]], + ['nested inside metadata', (error: Error) => [{ details: { error } }]], + ])('keeps bound values out of colorized output when passed as %s', (_, args) => { + new Logger('Test', { enabled: true, colorize: true, logLevel: LogLevel.DEBUG }).error( + 'Failed to query rows:', + ...args(queryError('alice@example.com')) + ) + + const output = consoleOutput() + expect(output).toContain('params: [redacted]') + expect(output).not.toContain('alice@example.com') + }) + + test.each([ + ['a bare argument', (error: Error) => [error]], + ['an object field', (error: Error) => [{ error }]], + ])('keeps bound values out of the exported log record when passed as %s', (_, args) => { const emit = vi.fn() const getLoggerSpy = vi .spyOn(logs, 'getLogger') .mockReturnValue({ emit, enabled: () => true }) try { - createEnabledLogger().error('Failed to query rows:', queryError('alice@example.com')) + createEnabledLogger().error( + 'Failed to query rows:', + ...args(queryError('alice@example.com')) + ) const { attributes } = emit.mock.calls[0][0] expect(JSON.stringify(attributes)).not.toContain('alice@example.com') @@ -257,6 +290,18 @@ describe('Logger', () => { } }) + test('emits a line for a nested error that references itself', () => { + const error = Object.assign(new Error('self-referencing failure'), { + context: {} as Record, + }) + error.context.error = error + + expect(() => createEnabledLogger().error('Failed', { details: { error } })).not.toThrow() + const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string) + expect(parsed.details.error.message).toBe('self-referencing failure') + expect(parsed.details.error.context.error).toBe('[Circular]') + }) + test('leaves an unwrapped error without cause fields', () => { createEnabledLogger().error('Request failed', { error: new Error('plain failure') }) diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index f8671561ba9..7a4bfb5699a 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -132,61 +132,14 @@ const getLogConfig = () => { } } -/** - * Renders an error as the plain object `JSON.stringify` cannot produce for it. - * - * `message`, `stack` and `name` are non-enumerable on `Error.prototype`, so a - * plain stringify emits `{}`. Own enumerable properties are copied too — driver - * and HTTP errors carry the useful part (`code`, `status`) there. - */ -const errorToPlainObject = (error: Error, isDev: boolean): Record => { - const errorObj: Record = { - message: error.message, - stack: isDev ? error.stack : undefined, - name: error.name, - } - for (const key of Object.keys(error)) { - if (!(key in errorObj)) { - errorObj[key] = (error as unknown as Record)[key] - } - } - return errorObj -} - -/** - * Format objects for logging - * - * Errors held under a key are unwrapped as well as bare ones — `{ error }` is - * the common call shape, and it would otherwise print as `{"error":{}}`. - */ -const formatObject = (obj: unknown, isDev: boolean): string => { - try { - if (obj instanceof Error) { - return JSON.stringify(errorToPlainObject(obj, isDev), null, isDev ? 2 : 0) - } - if (isRecordLike(obj)) { - let unwrapped: Record | undefined - for (const [key, value] of Object.entries(obj as Record)) { - if (!(value instanceof Error)) continue - unwrapped ??= { ...(obj as Record) } - unwrapped[key] = errorToPlainObject(value, isDev) - } - if (unwrapped) { - return JSON.stringify(unwrapped, null, isDev ? 2 : 0) - } - } - return JSON.stringify(obj, null, isDev ? 2 : 0) - } catch { - return '[Circular or Non-Serializable Object]' - } -} - interface LoggedError { message: string stack?: string /** `"Name: message"` of the deepest `.cause` link, present only when the error wraps another. */ cause?: string code?: string + /** Whether the message carried a bound-parameter tail, marking the error as a query wrapper. */ + redacted: boolean } /** @@ -212,9 +165,61 @@ const toLoggedError = (error: Error): LoggedError => { stack, ...(described.causeChain ? { cause: `${described.name}: ${described.message}` } : {}), ...(described.code ? { code: described.code } : {}), + redacted: message !== error.message, } } +/** + * Renders an error as the plain object `JSON.stringify` cannot produce for it. + * + * `message`, `stack` and `name` are non-enumerable on `Error.prototype`, so a + * plain stringify emits `{}` — or, for an error with own enumerable properties, + * only those. Own properties are copied because driver and HTTP errors carry the + * useful part (`code`, `status`) there, except what `toLoggedError` replaces: a + * query wrapper's `params` holds the redacted values, and a summarized `cause` + * would carry the driver's `detail`. + */ +const toPlainError = (error: Error, includeStack: boolean): Record => { + const logged = toLoggedError(error) + const plain: Record = { + message: logged.message, + stack: includeStack ? logged.stack : undefined, + name: error.name, + ...(logged.cause ? { cause: logged.cause } : {}), + ...(logged.code ? { code: logged.code } : {}), + } + for (const key of Object.keys(error)) { + if (key in plain || (logged.redacted && key === 'params')) continue + plain[key] = (error as unknown as Record)[key] + } + return plain +} + +/** JSON replacer that serializes every `Error`, however deeply nested, as its plain form. */ +const errorReplacer = + (includeStack: boolean) => + (_key: string, value: unknown): unknown => + value instanceof Error ? toPlainError(value, includeStack) : value + +/** Format objects for logging. */ +const formatObject = (obj: unknown, isDev: boolean): string => { + try { + return JSON.stringify(obj, errorReplacer(isDev), isDev ? 2 : 0) + } catch { + return '[Circular or Non-Serializable Object]' + } +} + +/** The error a line is about: the first bare `Error` argument, else the first `{ error }` field. */ +const primaryError = (args: unknown[]): Error | undefined => { + const bare = args.find((arg) => arg instanceof Error) + if (bare) return bare as Error + for (const arg of args) { + if (isRecordLike(arg) && arg.error instanceof Error) return arg.error + } + return undefined +} + /** Adds an error's cause fields to the entry without displacing caller-supplied values. */ const assignErrorCause = (entry: Record, logged: LoggedError) => { if (logged.cause !== undefined && entry.errorCause === undefined) entry.errorCause = logged.cause @@ -262,9 +267,14 @@ const mergeArgs = (entry: Record, args: unknown[]): Record { const ancestors: object[] = [] + /** What `JSON.stringify` descends into for each ancestor — an error's plain form, not the error. */ + const holders: object[] = [] return function (this: unknown, _key: string, value: unknown): unknown { if (typeof value === 'bigint') return value.toString() if (value === null || typeof value !== 'object') return value @@ -275,10 +285,15 @@ const tolerantReplacer = () => { * appearance of a merely repeated reference `[Circular]` and discard real * data, since a payload that references one object twice has no cycle. */ - while (ancestors.length > 0 && ancestors[ancestors.length - 1] !== this) ancestors.pop() + while (holders.length > 0 && holders[holders.length - 1] !== this) { + holders.pop() + ancestors.pop() + } if (ancestors.includes(value)) return '[Circular]' + const serialized = value instanceof Error ? toPlainError(value, false) : value ancestors.push(value) - return value + holders.push(serialized) + return serialized } } @@ -292,7 +307,7 @@ const tolerantReplacer = () => { */ const serializeEntry = (base: Record, args: unknown[]): string => { try { - return JSON.stringify(mergeArgs({ ...base }, args)) + return JSON.stringify(mergeArgs({ ...base }, args), errorReplacer(false)) } catch {} try { @@ -628,9 +643,9 @@ function emitOtelLogRecord( for (const [key, value] of Object.entries(filterUndefined(metadata))) { attributes[key] = String(value) } - const firstError = args.find((arg) => arg instanceof Error) as Error | undefined - if (firstError) { - const logged = toLoggedError(firstError) + const error = primaryError(args) + if (error) { + const logged = toLoggedError(error) attributes['error.message'] = logged.message if (logged.stack) attributes['error.stack'] = logged.stack if (logged.cause) attributes['error.cause'] = logged.cause @@ -638,7 +653,10 @@ function emitOtelLogRecord( const plainArgs = args.filter((arg) => !(arg instanceof Error)) if (plainArgs.length > 0) { try { - attributes['log.args'] = JSON.stringify(plainArgs).slice(0, OTEL_LOG_ARG_MAX_CHARS) + attributes['log.args'] = JSON.stringify(plainArgs, errorReplacer(false)).slice( + 0, + OTEL_LOG_ARG_MAX_CHARS + ) } catch { attributes['log.args'] = String(plainArgs).slice(0, OTEL_LOG_ARG_MAX_CHARS) } From b47175cc2c7f883cd048aa7fcf7a55f73573e90e Mon Sep 17 00:00:00 2001 From: Waleed Latif Date: Fri, 2 Oct 2026 01:50:01 -0700 Subject: [PATCH 3/3] fix(logging): report the cause of the error the line reports --- packages/logger/src/index.test.ts | 15 +++++++++++++++ packages/logger/src/index.ts | 23 +++++++++++++++-------- 2 files changed, 30 insertions(+), 8 deletions(-) diff --git a/packages/logger/src/index.test.ts b/packages/logger/src/index.test.ts index 2c61849769b..a48f79b97cd 100644 --- a/packages/logger/src/index.test.ts +++ b/packages/logger/src/index.test.ts @@ -224,6 +224,21 @@ describe('Logger', () => { expect(parsed.errorCode).toBe('57014') }) + test('reports the cause of the same error the line reports when given two', () => { + const conflict = Object.assign(new Error('duplicate key value'), { + name: 'PostgresError', + code: '23505', + }) + const second = new Error('Failed query: insert into "t" values ($1)', { cause: conflict }) + + createEnabledLogger().error('Retry failed', queryError('tbl_1'), second) + + const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string) + expect(parsed.error).toBe(second.message) + expect(parsed.errorCause).toBe('PostgresError: duplicate key value') + expect(parsed.errorCode).toBe('23505') + }) + test.each([ ['an object field', (error: Error) => [{ error }]], ['a bare argument', (error: Error) => [error]], diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 7a4bfb5699a..304e070c5e3 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -210,10 +210,15 @@ const formatObject = (obj: unknown, isDev: boolean): string => { } } -/** The error a line is about: the first bare `Error` argument, else the first `{ error }` field. */ +/** + * The error a line is about, chosen as `mergeArgs` chooses it: the last bare + * `Error` argument, else the first `{ error }` field. + */ const primaryError = (args: unknown[]): Error | undefined => { - const bare = args.find((arg) => arg instanceof Error) - if (bare) return bare as Error + for (let i = args.length - 1; i >= 0; i--) { + const arg = args[i] + if (arg instanceof Error) return arg + } for (const arg of args) { if (isRecordLike(arg) && arg.error instanceof Error) return arg.error } @@ -238,13 +243,14 @@ const assignErrorCause = (entry: Record, logged: LoggedError) = * cause and its code go in `errorCause` and `errorCode`. */ const mergeArgs = (entry: Record, args: unknown[]): Record => { + /** The error whose stack the line carries; its cause is assigned last so a later error cannot inherit an earlier one's. */ + let reported: LoggedError | undefined for (const arg of args) { if (arg === null || arg === undefined) continue if (arg instanceof Error) { - const logged = toLoggedError(arg) - entry.error = logged.message - entry.stack = logged.stack - assignErrorCause(entry, logged) + reported = toLoggedError(arg) + entry.error = reported.message + entry.stack = reported.stack } else if (typeof arg === 'object') { const source = arg as Record for (const key of Object.keys(source)) { @@ -254,7 +260,7 @@ const mergeArgs = (entry: Record, args: unknown[]): Record, args: unknown[]): Record