Skip to content

Commit 1beffd3

Browse files
committed
fix(logging): name the driver cause and redact bound params in logged errors
1 parent 70412cc commit 1beffd3

3 files changed

Lines changed: 136 additions & 9 deletions

File tree

‎apps/sim/lib/workflows/persistence/utils.ts‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -295,7 +295,10 @@ export async function loadDeployedWorkflowState(
295295
await resolveWorkspaceId(workflowId, providedWorkspaceId)
296296
)
297297
} catch (error) {
298-
logger.error(`Error loading deployed workflow state ${workflowId}:`, error)
298+
// An undeployed workflow is an outcome each caller handles, not a load failure.
299+
if (!(error instanceof NoActiveDeploymentError)) {
300+
logger.error(`Error loading deployed workflow state ${workflowId}:`, error)
301+
}
299302
throw error
300303
}
301304
}

‎packages/logger/src/index.test.ts‎

Lines changed: 77 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -188,4 +188,81 @@ describe('Logger', () => {
188188
expect(parsed.metadataError).toBe(true)
189189
})
190190
})
191+
192+
describe('wrapped driver errors', () => {
193+
const createEnabledLogger = () =>
194+
new Logger('Test', { enabled: true, colorize: false, logLevel: LogLevel.DEBUG })
195+
196+
/** Mirrors Drizzle's `DrizzleQueryError`: SQL plus bound values, wrapping the driver error. */
197+
const queryError = (params: string) => {
198+
const cause = Object.assign(new Error('canceling statement due to statement timeout'), {
199+
name: 'PostgresError',
200+
code: '57014',
201+
})
202+
const error = new Error(
203+
`Failed query: select "id" from "user_table_rows" where "table_id" = $1 limit $2\nparams: ${params}`,
204+
{ cause }
205+
)
206+
error.name = 'DrizzleQueryError'
207+
return error
208+
}
209+
210+
test('names the deepest cause and its code on the line', () => {
211+
createEnabledLogger().error('Failed to query rows:', { error: queryError('tbl_1,52') })
212+
213+
const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string)
214+
expect(parsed.errorCause).toBe('PostgresError: canceling statement due to statement timeout')
215+
expect(parsed.errorCode).toBe('57014')
216+
})
217+
218+
test.each([
219+
['an object field', (error: Error) => [{ error }]],
220+
['a bare argument', (error: Error) => [error]],
221+
])('keeps bound values out of the message and stack when passed as %s', (_, args) => {
222+
createEnabledLogger().error(
223+
'Failed to query rows:',
224+
...args(queryError('alice@example.com,52'))
225+
)
226+
227+
const line = consoleErrorSpy.mock.calls[0][0] as string
228+
expect(line).not.toContain('alice@example.com')
229+
const parsed = JSON.parse(line)
230+
expect(parsed.error).toContain('Failed query: select "id"')
231+
expect(parsed.error).toContain('params: [redacted]')
232+
expect(parsed.stack).toContain('params: [redacted]')
233+
expect(parsed.stack).toMatch(/\n\s+at /)
234+
})
235+
236+
test('keeps bound values out of an error logged under another key', () => {
237+
createEnabledLogger().error('Insert failed', { dbError: queryError('alice@example.com') })
238+
239+
expect(consoleErrorSpy.mock.calls[0][0] as string).not.toContain('alice@example.com')
240+
})
241+
242+
test('keeps bound values out of the exported log record', () => {
243+
const emit = vi.fn()
244+
const getLoggerSpy = vi
245+
.spyOn(logs, 'getLogger')
246+
.mockReturnValue({ emit, enabled: () => true })
247+
try {
248+
createEnabledLogger().error('Failed to query rows:', queryError('alice@example.com'))
249+
250+
const { attributes } = emit.mock.calls[0][0]
251+
expect(JSON.stringify(attributes)).not.toContain('alice@example.com')
252+
expect(attributes['error.cause']).toBe(
253+
'PostgresError: canceling statement due to statement timeout'
254+
)
255+
} finally {
256+
getLoggerSpy.mockRestore()
257+
}
258+
})
259+
260+
test('leaves an unwrapped error without cause fields', () => {
261+
createEnabledLogger().error('Request failed', { error: new Error('plain failure') })
262+
263+
const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string)
264+
expect(parsed.error).toBe('plain failure')
265+
expect(parsed).not.toHaveProperty('errorCause')
266+
})
267+
})
191268
})

‎packages/logger/src/index.ts‎

Lines changed: 55 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
* Provides standardized console logging with environment-aware configuration.
66
*/
77
import { logs, SeverityNumber } from '@opentelemetry/api-logs'
8+
import { describeError, redactBoundParameters } from '@sim/utils/errors'
89
import { filterUndefined, isRecordLike } from '@sim/utils/object'
910
import chalk from 'chalk'
1011
import { getRequestContext, type RequestContext } from './request-context'
@@ -180,6 +181,46 @@ const formatObject = (obj: unknown, isDev: boolean): string => {
180181
}
181182
}
182183

184+
interface LoggedError {
185+
message: string
186+
stack?: string
187+
/** `"Name: message"` of the deepest `.cause` link, present only when the error wraps another. */
188+
cause?: string
189+
code?: string
190+
}
191+
192+
/**
193+
* The fields a log line keeps for an error.
194+
*
195+
* Drizzle's `DrizzleQueryError` appends `\nparams: <values>` — user data — to
196+
* its message, and the stack repeats the message, so both are redacted. The
197+
* wrapper's message is only the failing SQL; the reason (a statement timeout, a
198+
* constraint violation) lives on the driver error in `.cause`, which no field
199+
* would otherwise carry.
200+
*/
201+
const toLoggedError = (error: Error): LoggedError => {
202+
const message = redactBoundParameters(error.message)
203+
const stack =
204+
error.stack === undefined || message === error.message
205+
? error.stack
206+
: error.stack.includes(error.message)
207+
? error.stack.replace(error.message, () => message)
208+
: redactBoundParameters(error.stack)
209+
const described = describeError(error)
210+
return {
211+
message,
212+
stack,
213+
...(described.causeChain ? { cause: `${described.name}: ${described.message}` } : {}),
214+
...(described.code ? { code: described.code } : {}),
215+
}
216+
}
217+
218+
/** Adds an error's cause fields to the entry without displacing caller-supplied values. */
219+
const assignErrorCause = (entry: Record<string, unknown>, logged: LoggedError) => {
220+
if (logged.cause !== undefined && entry.errorCause === undefined) entry.errorCause = logged.cause
221+
if (logged.code !== undefined && entry.errorCode === undefined) entry.errorCode = logged.code
222+
}
223+
183224
/**
184225
* Merges caller-supplied log arguments into the structured entry.
185226
*
@@ -188,23 +229,27 @@ const formatObject = (obj: unknown, isDev: boolean): string => {
188229
* is by far the most common call shape, which would otherwise reduce the one
189230
* field worth reading to an empty object. Errors nested in an object argument
190231
* are therefore unwrapped like a bare `Error` argument. `error` stays a plain
191-
* message string so log queries can group on it; richer diagnostics are opt-in
192-
* via `describeError` from `@sim/utils/errors`.
232+
* message string so log queries can group on it; the primary error's deepest
233+
* cause and its code go in `errorCause` and `errorCode`.
193234
*/
194235
const mergeArgs = (entry: Record<string, unknown>, args: unknown[]): Record<string, unknown> => {
195236
for (const arg of args) {
196237
if (arg === null || arg === undefined) continue
197238
if (arg instanceof Error) {
198-
entry.error = arg.message
199-
entry.stack = arg.stack
239+
const logged = toLoggedError(arg)
240+
entry.error = logged.message
241+
entry.stack = logged.stack
242+
assignErrorCause(entry, logged)
200243
} else if (typeof arg === 'object') {
201244
const source = arg as Record<string, unknown>
202245
for (const key of Object.keys(source)) {
203246
const value = source[key]
204247
if (value instanceof Error) {
205-
entry[key] = value.message
248+
const logged = toLoggedError(value)
249+
entry[key] = logged.message
206250
if (key === 'error' && entry.stack === undefined) {
207-
entry.stack = value.stack
251+
entry.stack = logged.stack
252+
assignErrorCause(entry, logged)
208253
}
209254
} else {
210255
entry[key] = value
@@ -585,8 +630,10 @@ function emitOtelLogRecord(
585630
}
586631
const firstError = args.find((arg) => arg instanceof Error) as Error | undefined
587632
if (firstError) {
588-
attributes['error.message'] = firstError.message
589-
if (firstError.stack) attributes['error.stack'] = firstError.stack
633+
const logged = toLoggedError(firstError)
634+
attributes['error.message'] = logged.message
635+
if (logged.stack) attributes['error.stack'] = logged.stack
636+
if (logged.cause) attributes['error.cause'] = logged.cause
590637
}
591638
const plainArgs = args.filter((arg) => !(arg instanceof Error))
592639
if (plainArgs.length > 0) {

0 commit comments

Comments
 (0)