mirror of
https://github.com/simstudioai/sim.git
synced 2026-09-24 15:45:35 +08:00
fix(logger, blocks): log nested errors and stop spurious model-selection warnings (#6706)
* fix(logger, blocks): log nested errors and stop spurious model-selection warnings
Two production defects found in the prod logs, neither release-related.
logger: mergeArgs copied object arguments verbatim, so an Error held under a
key stayed an Error instance and JSON.stringify rendered it {} — message and
stack are non-enumerable on Error.prototype. 399 call sites use the
logger.x('msg', { error }) shape and every one logged error: {}, which is why
BlockOutputs failures (10k/week) were undiagnosable. The colorized path had
the same hole via formatObject.
blocks: router, evaluator and agent resolved config.tool through
getBaseModelProviders(), which deliberately excludes gateway providers
(OpenRouter, vLLM, LiteLLM, Ollama, ...). A valid openrouter/* model therefore
threw "Invalid model selected", as did a model still holding an unresolved
<variable.x> at serialization time — ~140 warnings/day. The value is cosmetic
(every handler re-derives the provider from the resolved model), so the throw
bought nothing.
- unwrap keyed Errors on both the structured and colorized log paths
- keep `error` a plain message string so log queries can group on it
- resolve serialized provider ids through getProviderFromModel, the same
resolver the executor uses, via one shared helper for all four call sites
- drop the unreachable `if (!model)` checks behind `params.model || default`
* fix(blocks): move the fallback rationale into TSDoc
The repo forbids non-TSDoc comments; the explanation for why recovery returns
a constant instead of resolving again belongs on the declaration anyway.
This commit is contained in:
@@ -6,6 +6,7 @@ import {
|
||||
getModelCapabilityCondition,
|
||||
getModelOptions,
|
||||
getProviderCredentialSubBlocks,
|
||||
getSerializedModelProviderId,
|
||||
normalizeFileInput,
|
||||
RESPONSE_FORMAT_WAND_CONFIG,
|
||||
} from '@/blocks/utils'
|
||||
@@ -29,6 +30,9 @@ import { useSubBlockStore } from '@/stores/workflows/subblock/store'
|
||||
import type { ToolResponse } from '@/tools/types'
|
||||
|
||||
const logger = createLogger('AgentBlock')
|
||||
|
||||
/** Model the agent block falls back to when `model` is unset or the auto pseudo-model. */
|
||||
const AGENT_FALLBACK_MODEL = 'claude-sonnet-5'
|
||||
const MODELS_WITH_REASONING_EFFORT = getModelsWithReasoningEffort()
|
||||
const MODELS_WITH_VERBOSITY = getModelsWithVerbosity()
|
||||
const MODELS_WITH_THINKING = getModelsWithThinking()
|
||||
@@ -521,21 +525,10 @@ Return ONLY the JSON array.`,
|
||||
],
|
||||
config: {
|
||||
tool: (params: Record<string, any>) => {
|
||||
const model = params.model || 'claude-sonnet-5'
|
||||
if (!model) {
|
||||
throw new Error('No model selected')
|
||||
}
|
||||
// sim-auto resolves to a concrete pool model at execution time, where
|
||||
// the agent handler derives the provider from the resolved model and
|
||||
// never reads this serialized value. Serialization still needs the
|
||||
// same provider-id shape every other model stores, so look up the
|
||||
// runtime fallback model's provider.
|
||||
const lookupModel = isAutoModel(model) ? 'claude-sonnet-5' : model
|
||||
const tool = getBaseModelProviders()[lookupModel]
|
||||
if (!tool) {
|
||||
throw new Error(`Invalid model selected: ${model}`)
|
||||
}
|
||||
return tool
|
||||
const model = params.model || AGENT_FALLBACK_MODEL
|
||||
// sim-auto has no provider of its own until the pool resolves it at execution time.
|
||||
const lookupModel = isAutoModel(model) ? AGENT_FALLBACK_MODEL : model
|
||||
return getSerializedModelProviderId(lookupModel, AGENT_FALLBACK_MODEL)
|
||||
},
|
||||
params: (params: Record<string, any>) => {
|
||||
const normalizedFiles = normalizeFileInput(params.files)
|
||||
|
||||
@@ -4,10 +4,9 @@ import type { BlockConfig, ParamType } from '@/blocks/types'
|
||||
import {
|
||||
getModelOptions,
|
||||
getProviderCredentialSubBlocks,
|
||||
getSerializedModelProviderId,
|
||||
PROVIDER_CREDENTIAL_INPUTS,
|
||||
} from '@/blocks/utils'
|
||||
import { getBaseModelProviders } from '@/providers/models'
|
||||
import type { ProviderId } from '@/providers/types'
|
||||
import type { ToolResponse } from '@/tools/types'
|
||||
|
||||
const logger = createLogger('EvaluatorBlock')
|
||||
@@ -253,17 +252,7 @@ export const EvaluatorBlock: BlockConfig<EvaluatorResponse> = {
|
||||
'deepseek_reasoner',
|
||||
],
|
||||
config: {
|
||||
tool: (params: Record<string, any>) => {
|
||||
const model = params.model || 'gpt-4o'
|
||||
if (!model) {
|
||||
throw new Error('No model selected')
|
||||
}
|
||||
const tool = getBaseModelProviders()[model as ProviderId]
|
||||
if (!tool) {
|
||||
throw new Error(`Invalid model selected: ${model}`)
|
||||
}
|
||||
return tool
|
||||
},
|
||||
tool: (params: Record<string, any>) => getSerializedModelProviderId(params.model),
|
||||
},
|
||||
},
|
||||
inputs: {
|
||||
|
||||
@@ -3,10 +3,9 @@ import { AuthMode, type BlockConfig } from '@/blocks/types'
|
||||
import {
|
||||
getModelOptions,
|
||||
getProviderCredentialSubBlocks,
|
||||
getSerializedModelProviderId,
|
||||
PROVIDER_CREDENTIAL_INPUTS,
|
||||
} from '@/blocks/utils'
|
||||
import { getBaseModelProviders } from '@/providers/models'
|
||||
import type { ProviderId } from '@/providers/types'
|
||||
import type { ToolResponse } from '@/tools/types'
|
||||
|
||||
interface RouterResponse extends ToolResponse {
|
||||
@@ -215,17 +214,7 @@ export const RouterBlock: BlockConfig<RouterResponse> = {
|
||||
'deepseek_reasoner',
|
||||
],
|
||||
config: {
|
||||
tool: (params: Record<string, any>) => {
|
||||
const model = params.model || 'gpt-4o'
|
||||
if (!model) {
|
||||
throw new Error('No model selected')
|
||||
}
|
||||
const tool = getBaseModelProviders()[model as ProviderId]
|
||||
if (!tool) {
|
||||
throw new Error(`Invalid model selected: ${model}`)
|
||||
}
|
||||
return tool
|
||||
},
|
||||
tool: (params: Record<string, any>) => getSerializedModelProviderId(params.model),
|
||||
},
|
||||
},
|
||||
inputs: {
|
||||
@@ -325,17 +314,7 @@ export const RouterV2Block: BlockConfig<RouterV2Response> = {
|
||||
'deepseek_reasoner',
|
||||
],
|
||||
config: {
|
||||
tool: (params: Record<string, any>) => {
|
||||
const model = params.model || 'gpt-4o'
|
||||
if (!model) {
|
||||
throw new Error('No model selected')
|
||||
}
|
||||
const tool = getBaseModelProviders()[model as ProviderId]
|
||||
if (!tool) {
|
||||
throw new Error(`Invalid model selected: ${model}`)
|
||||
}
|
||||
return tool
|
||||
},
|
||||
tool: (params: Record<string, any>) => getSerializedModelProviderId(params.model),
|
||||
},
|
||||
},
|
||||
inputs: {
|
||||
|
||||
@@ -72,11 +72,13 @@ import {
|
||||
BUILT_IN_TOOL_TYPES,
|
||||
getApiKeyCondition,
|
||||
getDependsOnFields,
|
||||
getSerializedModelProviderId,
|
||||
getSubBlocksDependingOnChange,
|
||||
parseOptionalBooleanInput,
|
||||
parseOptionalJsonInput,
|
||||
parseOptionalNumberInput,
|
||||
} from '@/blocks/utils'
|
||||
import { getProviderFromModel } from '@/providers/utils'
|
||||
|
||||
describe('BUILT_IN_TOOL_TYPES', () => {
|
||||
it('classifies the current File block instead of the legacy File block', () => {
|
||||
@@ -464,3 +466,46 @@ describe('getSubBlocksDependingOnChange', () => {
|
||||
).toEqual(['projectId'])
|
||||
})
|
||||
})
|
||||
|
||||
describe('getSerializedModelProviderId', () => {
|
||||
const resolver = vi.mocked(getProviderFromModel)
|
||||
|
||||
beforeEach(() => {
|
||||
resolver.mockReset()
|
||||
resolver.mockImplementation(((model: string) => {
|
||||
if (model.startsWith('openrouter/')) return 'openrouter'
|
||||
if (model === 'gpt-4o') return 'openai'
|
||||
if (model === 'claude-sonnet-5') return 'anthropic'
|
||||
throw new Error(`No provider found for model: ${model}`)
|
||||
}) as unknown as typeof getProviderFromModel)
|
||||
})
|
||||
|
||||
it('resolves a gateway model that the base model map deliberately omits', () => {
|
||||
expect(getSerializedModelProviderId('openrouter/meta-llama/llama-4-maverick')).toBe(
|
||||
'openrouter'
|
||||
)
|
||||
})
|
||||
|
||||
it('uses the fallback model when the model is still an unresolved reference', () => {
|
||||
expect(getSerializedModelProviderId('openrouter/<variable.vllm>')).toBe('openai')
|
||||
expect(resolver).not.toHaveBeenCalledWith('openrouter/<variable.vllm>')
|
||||
})
|
||||
|
||||
it('honours a caller-supplied fallback model', () => {
|
||||
expect(getSerializedModelProviderId(undefined, 'claude-sonnet-5')).toBe('anthropic')
|
||||
})
|
||||
|
||||
it('never throws when the resolver rejects the model', () => {
|
||||
expect(() => getSerializedModelProviderId('totally-unknown-model')).not.toThrow()
|
||||
expect(getSerializedModelProviderId('totally-unknown-model')).toBe('openai')
|
||||
})
|
||||
|
||||
it('never throws when the resolver rejects every model, including the fallback', () => {
|
||||
resolver.mockImplementation((() => {
|
||||
throw new Error('Provider "openai" is not available')
|
||||
}) as unknown as typeof getProviderFromModel)
|
||||
|
||||
expect(() => getSerializedModelProviderId('gpt-4o')).not.toThrow()
|
||||
expect(getSerializedModelProviderId('gpt-4o')).toBe('openai')
|
||||
})
|
||||
})
|
||||
|
||||
@@ -21,6 +21,7 @@ import {
|
||||
SIM_AUTO_MODEL_ID,
|
||||
} from '@/providers/models'
|
||||
import { isPiSupportedModel } from '@/providers/pi-providers'
|
||||
import type { ProviderId } from '@/providers/types'
|
||||
import { getProviderFromModel } from '@/providers/utils'
|
||||
import { useProvidersStore } from '@/stores/providers/store'
|
||||
|
||||
@@ -236,6 +237,45 @@ function shouldRequireApiKeyForModel(model: string): boolean {
|
||||
return true
|
||||
}
|
||||
|
||||
/** Model whose provider is recorded when a block's own `model` cannot be resolved. */
|
||||
const SERIALIZATION_FALLBACK_MODEL = 'gpt-4o'
|
||||
|
||||
/** Last-resort provider for when even {@link SERIALIZATION_FALLBACK_MODEL} cannot be resolved. */
|
||||
const SERIALIZATION_FALLBACK_PROVIDER: ProviderId = 'openai'
|
||||
|
||||
/**
|
||||
* Provider id a model-driven block records for `model` during serialization.
|
||||
*
|
||||
* Serialization runs before variable resolution, and every model block's handler
|
||||
* re-derives the provider from the *resolved* model without ever reading this
|
||||
* value — so it only has to be shape-correct, and it must never throw. Two cases
|
||||
* reach here that {@link getBaseModelProviders} cannot answer: `model` may still
|
||||
* hold a `<variable.x>` reference, and gateway providers (OpenRouter, vLLM,
|
||||
* LiteLLM, Ollama, …) are deliberately absent from that map even when the model
|
||||
* id is perfectly valid. A reference resolves to {@link SERIALIZATION_FALLBACK_MODEL}'s
|
||||
* provider; anything else is left to `getProviderFromModel`, which defaults an
|
||||
* unrecognised id to `ollama` rather than failing serialization with an error the
|
||||
* user cannot act on.
|
||||
*
|
||||
* The remaining throw is a blacklisted provider or model, which is env-driven and
|
||||
* can name the fallback itself — so recovery returns
|
||||
* {@link SERIALIZATION_FALLBACK_PROVIDER} outright rather than resolving a second
|
||||
* time through the function that just threw.
|
||||
*/
|
||||
export function getSerializedModelProviderId(
|
||||
model: unknown,
|
||||
fallbackModel: string = SERIALIZATION_FALLBACK_MODEL
|
||||
): ProviderId {
|
||||
const candidate =
|
||||
typeof model === 'string' && model && !containsReference(model) ? model : fallbackModel
|
||||
|
||||
try {
|
||||
return getProviderFromModel(candidate)
|
||||
} catch {
|
||||
return SERIALIZATION_FALLBACK_PROVIDER
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Visibility condition for a model-tuning field that only some models accept, such as
|
||||
* reasoning effort or verbosity. Gates on the capability list, but keeps the field visible
|
||||
|
||||
@@ -948,6 +948,15 @@ describe('Provider Management', () => {
|
||||
expect(getProviderFromModel('unknown-model')).toBe('ollama')
|
||||
})
|
||||
|
||||
it('should resolve gateway models that getBaseModelProviders deliberately omits', () => {
|
||||
// getBaseModelProviders() filters these providers out entirely, so a model
|
||||
// block that looked models up there rejected valid ids like these.
|
||||
expect(getProviderFromModel('openrouter/meta-llama/llama-4-maverick')).toBe('openrouter')
|
||||
expect(getProviderFromModel('together/some-model')).toBe('together')
|
||||
expect(getProviderFromModel('fireworks/some-model')).toBe('fireworks')
|
||||
expect(getBaseModelProviders()['openrouter/meta-llama/llama-4-maverick']).toBeUndefined()
|
||||
})
|
||||
|
||||
it('should be case insensitive', () => {
|
||||
expect(getProviderFromModel('GPT-4O')).toBe('openai')
|
||||
expect(getProviderFromModel('CLAUDE-SONNET-4-0')).toBe('anthropic')
|
||||
|
||||
@@ -263,6 +263,46 @@ describe('Logger', () => {
|
||||
expect(parsed.self.self).toBe('[Circular]')
|
||||
})
|
||||
|
||||
test('should render an Error held under a key as its message, not {}', () => {
|
||||
const error = new Error('boom')
|
||||
|
||||
createEnabledLogger().error('failed', { error })
|
||||
|
||||
const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string)
|
||||
expect(parsed.error).toBe('boom')
|
||||
expect(parsed.stack).toBe(error.stack)
|
||||
})
|
||||
|
||||
test('should render an Error under a non-conventional key without hijacking stack', () => {
|
||||
createEnabledLogger().error('failed', { cause: new Error('inner'), stack: 'caller-supplied' })
|
||||
|
||||
const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string)
|
||||
expect(parsed.cause).toBe('inner')
|
||||
expect(parsed.stack).toBe('caller-supplied')
|
||||
})
|
||||
|
||||
test('should keep sibling keys alongside an Error value', () => {
|
||||
createEnabledLogger().error('failed', { error: new Error('boom'), toolId: 'slack_message' })
|
||||
|
||||
const parsed = JSON.parse(consoleErrorSpy.mock.calls[0][0] as string)
|
||||
expect(parsed.error).toBe('boom')
|
||||
expect(parsed.toolId).toBe('slack_message')
|
||||
})
|
||||
|
||||
test('should unwrap an Error held under a key on the colorized path too', () => {
|
||||
const colorized = new Logger('Test', {
|
||||
enabled: true,
|
||||
colorize: true,
|
||||
logLevel: LogLevel.DEBUG,
|
||||
})
|
||||
|
||||
colorized.error('failed', { error: new Error('boom') })
|
||||
|
||||
const printed = consoleErrorSpy.mock.calls[0].join(' ')
|
||||
expect(printed).toContain('boom')
|
||||
expect(printed).not.toContain('"error":{}')
|
||||
})
|
||||
|
||||
test('should emit a line instead of throwing on BigInt metadata', () => {
|
||||
expect(() => createEnabledLogger().error('boom', { size: 10n })).not.toThrow()
|
||||
expect(consoleErrorSpy).toHaveBeenCalledTimes(1)
|
||||
|
||||
@@ -130,23 +130,48 @@ 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<string, unknown> => {
|
||||
const errorObj: Record<string, unknown> = {
|
||||
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<string, unknown>)[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) {
|
||||
const errorObj: Record<string, unknown> = {
|
||||
message: obj.message,
|
||||
stack: isDev ? obj.stack : undefined,
|
||||
name: obj.name,
|
||||
return JSON.stringify(errorToPlainObject(obj, isDev), null, isDev ? 2 : 0)
|
||||
}
|
||||
if (obj && typeof obj === 'object' && !Array.isArray(obj)) {
|
||||
let unwrapped: Record<string, unknown> | undefined
|
||||
for (const [key, value] of Object.entries(obj as Record<string, unknown>)) {
|
||||
if (!(value instanceof Error)) continue
|
||||
unwrapped ??= { ...(obj as Record<string, unknown>) }
|
||||
unwrapped[key] = errorToPlainObject(value, isDev)
|
||||
}
|
||||
for (const key of Object.keys(obj)) {
|
||||
if (!(key in errorObj)) {
|
||||
errorObj[key] = (obj as unknown as Record<string, unknown>)[key]
|
||||
}
|
||||
if (unwrapped) {
|
||||
return JSON.stringify(unwrapped, null, isDev ? 2 : 0)
|
||||
}
|
||||
return JSON.stringify(errorObj, null, isDev ? 2 : 0)
|
||||
}
|
||||
return JSON.stringify(obj, null, isDev ? 2 : 0)
|
||||
} catch {
|
||||
@@ -154,7 +179,17 @@ const formatObject = (obj: unknown, isDev: boolean): string => {
|
||||
}
|
||||
}
|
||||
|
||||
/** Merges caller-supplied log arguments into the structured entry. */
|
||||
/**
|
||||
* Merges caller-supplied log arguments into the structured entry.
|
||||
*
|
||||
* `Error.message` and `Error.stack` are non-enumerable, so `JSON.stringify`
|
||||
* renders an error held under a key as `{}` — and `logger.x('...', { error })`
|
||||
* 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`.
|
||||
*/
|
||||
const mergeArgs = (entry: Record<string, unknown>, args: unknown[]): Record<string, unknown> => {
|
||||
for (const arg of args) {
|
||||
if (arg === null || arg === undefined) continue
|
||||
@@ -162,7 +197,18 @@ const mergeArgs = (entry: Record<string, unknown>, args: unknown[]): Record<stri
|
||||
entry.error = arg.message
|
||||
entry.stack = arg.stack
|
||||
} else if (typeof arg === 'object') {
|
||||
Object.assign(entry, arg)
|
||||
const source = arg as Record<string, unknown>
|
||||
for (const key of Object.keys(source)) {
|
||||
const value = source[key]
|
||||
if (value instanceof Error) {
|
||||
entry[key] = value.message
|
||||
if (key === 'error' && entry.stack === undefined) {
|
||||
entry.stack = value.stack
|
||||
}
|
||||
} else {
|
||||
entry[key] = value
|
||||
}
|
||||
}
|
||||
} else {
|
||||
entry.extra = arg
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user