Skip to content

Commit b746aa0

Browse files
os-zhuangclaude
andauthored
fix(service-automation): connector reconcile reports its cause structurally (#5575) (#5639)
The declarative connector reconcile's soft path (post `metadata:reloaded`) interpolated a foreign `err.message` into the log message at two call sites — auth resolution and provider-factory failure. Neither message is ours: the credential resolver is host-supplied and a provider factory is third-party code ADR-0097 invites, so the first one validating `providerConfig` with a strict Zod schema logs a multi-line dump whose first line is `[`. `ObjectLogger` writes one `<ts> <LEVEL> <msg>` record per call, so such a message spills onto lines with no level head and every line-oriented consumer of stderr (file sink, shipper, grep) reads them as unattributable fragments. `fail(msg, cause?)` now renders the cause per path: appended to the thrown message on the fatal (boot) path, since a throw is not a log record and the kernel prints it verbatim; handed to the logger's structured meta on the soft path. `flow-bind-diagnostics.ts` is generalized to `thrown-cause-diagnostics.ts` (`describeThrownForLog`) — nothing in it was ever flow-specific. Also fixes the producer this depends on: `ObjectLogger.error`/`fatal` dropped the `Logger` contract's declared third `meta` argument whenever the second was not an `Error`, so every contract-shaped `error(msg, undefined, { … })` call logged a bare message. About 15 such call sites across metadata, metadata-protocol, client and core/security were silently losing their diagnostics; the contract's two sibling implementations honour the slot, so the contract was right and this implementation was the outlier. The issue's stated harm mechanism is corrected in the module docs: `warn` goes to stdout, which serve's boot buffer filters, while `error` goes to stderr, which nothing in the CLI buffers — the boot buffer never sees this seam. Fixes #5575 Claude-Session: https://claude.ai/code/session_01BWS4heBoAitLmzCLhcYdbK Co-authored-by: Claude <noreply@anthropic.com>
1 parent 2b2175b commit b746aa0

8 files changed

Lines changed: 878 additions & 200 deletions

File tree

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,55 @@
1+
---
2+
"@objectstack/service-automation": patch
3+
"@objectstack/core": patch
4+
---
5+
6+
fix(service-automation): connector 物化失败的软路径改用结构化 `meta`;顺带修好 `ObjectLogger.error` 丢弃契约第三参的缺陷 (#5575)
7+
8+
## service-automation:`fail(msg, cause)`
9+
10+
`reconcileDeclaredConnectors` 的报错器有两条路径(ADR-0097):冷启动 `throw`(fatal),
11+
`metadata:reloaded` 之后 —— Studio publish、`os dev` 重编译 —— 记日志并让旧 connector
12+
继续服务(soft)。其中两个调用点把**外来**的 `err.message` 插进那条日志 message:
13+
`resolveInstanceAuth` 失败处,以及 provider factory 抛错处。这两个 message 都不是我们
14+
自己的:credential resolver 由宿主提供
15+
(`AutomationServicePluginOptions.credentialResolver`),provider factory 更是 ADR-0097
16+
明确鼓励第三方去写的代码 —— 第一个用严格 Zod schema 校验 `providerConfig` 的 factory
17+
抛出的就是 `ZodError`,它的 `.message` 是 issue 数组的多行 JSON dump,第一行是一个 `[`。
18+
19+
`ObjectLogger` 每次调用只写一条 `<ts> <LEVEL> <msg>` 记录,带换行的 message 会溢出到
20+
不带等级头的后续物理行,于是运行时 stderr 的每一个按行工作的消费者 —— 文件 sink、
21+
`docker logs`/journald 送进日志采集、一次 `grep ERROR` —— 都会把那些续行读成无法归属的
22+
垃圾记录:一条诊断散成 N 个碎片。与 #5048 在 flow 绑定接缝上是同一类,也是同一条 #4632
23+
原则:被搅烂的诊断比没有诊断更贵。
24+
25+
改法与 PR #5572 同源:`fail(msg, cause?)` —— message 是不含换行的自足句子,cause 按路径
26+
分别渲染。soft 路径把 cause 交给 logger 的**结构化 meta**(`issues[]` / `error`);fatal
27+
路径把 cause 文本接在抛出的 message 后面(`… cause: <text>`),因为 throw 不是日志记录,
28+
内核失败通道原样打印,多行 ZodError dump 在终端里本来就好读 —— 同一个 cause,两种受众,
29+
刻意不共用一种形状。`#5048` 引入的内部模块随之从 `flow-bind-diagnostics.ts` 更名为
30+
`thrown-cause-diagnostics.ts`(`describeThrownForLog`),因为它从来不是 flow 专属的:
31+
主题是日志管线,不是 metadata 类型。被拒键名仍放在 `unrecognized` 而不是 Zod 原本的
32+
`keys`(`ObjectLogger` 的脱敏表按子串匹配,`keys` 含 `key`)。
33+
34+
**一处订正**:#5575 的 issue 正文把此处的危害归给了 `serve` 的启动诊断缓冲
35+
(`BootLogCapture`)。那个缓冲看不到这条路径 —— `ObjectLogger` 把 `warn` 送 stdout(启动
36+
静默窗口只包了 `process.stdout.write`),`error`/`fatal` 送 **stderr**,而且 soft 路径在
37+
`metadata:reloaded` 之后才跑,窗口早已恢复。危害是上面那串按行消费者,以及日志查询根本
38+
无法按字段过滤;机制写进了模块文档,连同 `warn`/`error` 下游不同这件事本身。
39+
40+
## core:`ObjectLogger.error`/`fatal` 兑现契约声明的 `meta`
41+
42+
`Logger` 契约声明 `error(message, error?: Error, meta?)`。`ObjectLogger` 按形状分派,
43+
所以 meta 也允许出现在 `error` 位 —— 这份宽容没问题;**丢掉一个自己声明的参数**有问题:
44+
`error === undefined` 时旧代码走 `write(level, message, errorOrMeta)`,第三个参数从未被
45+
读取。于是每一个按契约书写的 `logger.error(msg, undefined, { … })` 都只输出一条裸 message,
46+
事实全部静默消失 —— `metadata`、`metadata-protocol`、`client`、`core/security` 里约 15 处
47+
调用点今天就是这样(其中 `metadata/src/endpoint-matcher.ts` 送的正是一个 Zod issue 数组)。
48+
契约的另外两个实现(`@objectstack/observability` 的 `ConsoleLogger`/`JsonLogger`)都老老实实
49+
用了这个位置,所以是契约对、这一个实现错:declared ≠ enforced。
50+
51+
三种形状现在都被兑现,两个位置同时带值时以更靠后的 `meta` 为准。这一处修好之后,上述
52+
调用点的诊断自动恢复(`client` 的 `HTTP request failed` 记录重新带上
53+
`{method, url, status, error}`)。connector 接缝改用契约的第三参而非第二参,是刻意的:
54+
把原始 error 塞进第二位会让每条记录都附带完整堆栈,ZodError 还会附带整段多行 dump ——
55+
正是我们要消灭的无界形状。

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

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -222,4 +222,80 @@ describe('ObjectLogger', () => {
222222
expect(fileLine).toMatch(/INFO file message/);
223223
});
224224
});
225+
226+
// ── the contract's `meta` slot on error/fatal (#5575) ───────────────────
227+
//
228+
// `Logger.error(message, error?: Error, meta?)` declares THREE parameters.
229+
// `ObjectLogger` dispatches by shape so a meta object may also ride in the
230+
// `error` slot — but until #5575 the `error === undefined` branch never read
231+
// the third argument at all, so the contract-shaped
232+
// `logger.error(msg, undefined, { … })` rendered a bare message and dropped
233+
// every fact. ~15 call sites in `metadata`/`metadata-protocol`/`client`/
234+
// `core/security` write exactly that shape, and both sibling `Logger`
235+
// implementations (`ConsoleLogger`/`JsonLogger`) honour it — the drop was
236+
// this class's alone.
237+
describe('error/fatal honour the contract meta slot (#5575)', () => {
238+
const stderrChunks: string[] = [];
239+
let restore: () => void;
240+
241+
beforeEach(() => {
242+
stderrChunks.length = 0;
243+
const spy = vi.spyOn(process.stderr, 'write').mockImplementation(((c: string | Uint8Array) => {
244+
stderrChunks.push(String(c));
245+
return true;
246+
}) as never);
247+
restore = () => spy.mockRestore();
248+
});
249+
afterEach(() => restore());
250+
251+
/** The single JSON record written by `fn`. */
252+
const recordOf = (fn: (log: ObjectLogger) => void): Record<string, unknown> => {
253+
const log = createLogger({ level: 'error', format: 'json' });
254+
fn(log);
255+
const lines = stderrChunks.join('').split('\n').filter(Boolean);
256+
expect(lines, 'one call must write exactly one physical line').toHaveLength(1);
257+
return JSON.parse(lines[0]) as Record<string, unknown>;
258+
};
259+
260+
it('delivers `meta` from the THIRD slot when the error slot is undefined', () => {
261+
const record = recordOf((log) =>
262+
log.error('reconcile failed', undefined, {
263+
issues: [{ code: 'unrecognized_keys', unrecognized: ['visibleIf'] }],
264+
}),
265+
);
266+
expect(record.msg).toBe('reconcile failed');
267+
// Pre-#5575 this whole field was absent: the record was `{msg}` only.
268+
expect(record.issues).toEqual([{ code: 'unrecognized_keys', unrecognized: ['visibleIf'] }]);
269+
});
270+
271+
it('still accepts a meta object in the error slot (the tolerated shape)', () => {
272+
const record = recordOf((log) => log.error('reconcile failed', { connector: 'billing' }));
273+
expect(record.connector).toBe('billing');
274+
});
275+
276+
it('merges both slots, with the later `meta` winning a collision', () => {
277+
const record = recordOf((log) =>
278+
log.error('both', { connector: 'billing', stage: 'auth' }, { stage: 'materialize' }),
279+
);
280+
expect(record.connector).toBe('billing');
281+
expect(record.stage).toBe('materialize');
282+
});
283+
284+
it('keeps rendering an Error in the error slot alongside third-slot meta', () => {
285+
const record = recordOf((log) => log.error('boom', new Error('upstream down'), { connector: 'billing' }));
286+
expect(record.connector).toBe('billing');
287+
expect((record.error as { message?: string }).message).toBe('upstream down');
288+
});
289+
290+
it('writes no context at all when neither slot is given', () => {
291+
const record = recordOf((log) => log.error('bare'));
292+
expect(Object.keys(record).sort()).toEqual(['level', 'msg', 'time']);
293+
});
294+
295+
it('applies the same three shapes to fatal', () => {
296+
const record = recordOf((log) => log.fatal('fatal meta', undefined, { connector: 'billing' }));
297+
expect(record.level).toBe('fatal');
298+
expect(record.connector).toBe('billing');
299+
});
300+
});
225301
});

‎packages/core/src/logger.ts‎

Lines changed: 40 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -247,19 +247,51 @@ export class ObjectLogger implements Logger {
247247
}
248248

249249
error(message: string, errorOrMeta?: Error | Record<string, any>, meta?: Record<string, any>): void {
250-
if (errorOrMeta instanceof Error) {
251-
this.write('error', message, meta, errorOrMeta);
252-
} else {
253-
this.write('error', message, errorOrMeta);
254-
}
250+
this.writeErrorLike('error', message, errorOrMeta, meta);
255251
}
256252

257253
fatal(message: string, errorOrMeta?: Error | Record<string, any>, meta?: Record<string, any>): void {
254+
this.writeErrorLike('fatal', message, errorOrMeta, meta);
255+
}
256+
257+
/**
258+
* `error`/`fatal` dispatch — the two levels whose contract has an `Error`
259+
* slot in front of `meta`.
260+
*
261+
* The `Logger` contract declares `error(message, error?: Error, meta?)`, and
262+
* `ObjectLogger` additionally tolerates a **meta object** in the `error`
263+
* slot because many in-repo call sites write `logger.error(msg, { … })`.
264+
* That tolerance is fine; dropping a parameter the contract *declares* is
265+
* not, and that is what the previous dispatch did:
266+
*
267+
* if (errorOrMeta instanceof Error) this.write(level, message, meta, errorOrMeta);
268+
* else this.write(level, message, errorOrMeta);
269+
*
270+
* With `error === undefined` the `else` branch passed `undefined` as the
271+
* meta and **never read the third argument**, so every contract-shaped
272+
* `logger.error(msg, undefined, { … })` call rendered a bare message with
273+
* its diagnostics silently gone — ~15 such call sites across `metadata`,
274+
* `metadata-protocol`, `client` and `core/security`, plus the connector
275+
* reconcile seam that found this (#5575). The contract's two sibling
276+
* implementations (`ConsoleLogger`/`JsonLogger` in `@objectstack/observability`)
277+
* both honour the slot, so the contract was right and this class was the
278+
* outlier — declared ≠ enforced, Prime Directive #10.
279+
*
280+
* All three shapes are now honoured. When both slots carry meta, `meta`
281+
* (the later, more specific argument) wins on a key collision.
282+
*/
283+
private writeErrorLike(
284+
level: 'error' | 'fatal',
285+
message: string,
286+
errorOrMeta?: Error | Record<string, any>,
287+
meta?: Record<string, any>,
288+
): void {
258289
if (errorOrMeta instanceof Error) {
259-
this.write('fatal', message, meta, errorOrMeta);
260-
} else {
261-
this.write('fatal', message, errorOrMeta);
290+
this.write(level, message, meta, errorOrMeta);
291+
return;
262292
}
293+
const merged = errorOrMeta && meta ? { ...errorOrMeta, ...meta } : (errorOrMeta ?? meta);
294+
this.write(level, message, merged);
263295
}
264296

265297
log(message: string, ...args: any[]): void {

0 commit comments

Comments
 (0)