Skip to content

finding(service-automation): builtin/wait-node.ts 里还有五处外来 cause 插进日志 message —— 其中三处是 #4632 亲自标为 error 的耐久性诊断,且已实测被切碎 #5737

Closed
#5911
Closed
finding(service-automation): builtin/wait-node.ts 里还有五处外来 cause 插进日志 message —— 其中三处是 #4632 亲自标为 error 的耐久性诊断,且已实测被切碎#5737
#5911
Assignees
hotlong
Labels
domain:servicespm:dispatchedpm:queue

Description

@os-zhuang
os-zhuang
opened on Aug 6, 2026

做 #5661(PR 见其正文)时,在同一条冷启动路径上实测到的旁生发现:plugin.ts 的 probe 接缝修好之后,同一次 boot 的 stderr 上仍然出现一条把整段多行驱动错误塞进 message 的记录 —— 它来自 packages/services/service-automation/src/builtin/wait-node.ts,不在 #5048 / #5575 / #5636 / #5660 / #5661 任何一单的范围内。

实测证据

给 sys_automation_run 的读取注入一个三行的驱动错误后,一次 boot 的 stderr 上有两条记录。第一条(#5661 修好的 probe 接缝)干净:

{"level":"error","msg":"[Automation] sys_automation_run could not be read at startup … the driver's own failure is in this record's meta.","error":"SQLITE_ERROR: no such table: sys_automation_run\n  at Database.prepare …\n  hint: …"}

第二条没有:

{"level":"error","msg":"[wait] suspended wait-timer re-arm ABORTED — … resume(runId). Cause: SQLITE_ERROR: no such table: sys_automation_run\n  at Database.prepare …\n  hint: …"}

注意 cause 在 msg 里面。JSON 格式下 JSON.stringify 把换行转义了所以还是一行;pretty / text 格式(os dev / os serve 的默认)下 ObjectLogger.write() 一次调用只加一个「时间戳 + 级别」记录头,于是这一条变成三个物理行、后两行无级别无时间戳 —— 文件 sink 当成三条独立记录存,grep ERROR 只捞到不含任何事实的那一行。这正是 cloud#971 的形态。

五处

行 级别 cause 来源 备注
wait-node.ts:98 error engine.resume() 返回的错误信封 result.error 定时唤醒时 store 不可达;Cause: ${result.error ?? 'store unavailable'}
wait-node.ts:216 warn job 服务(job.schedule 抛出) flow 执行期,不在 boot 静默窗口内,但仍是 warn,走 stdout
wait-node.ts:323 error 挂起态存储 / 数据源驱动 上面实测的那一条;#4632 耐久性诊断
wait-node.ts:346 error engine.resume() 抛出 overdue 运行再也叫不醒;#4632
wait-node.ts:387 error job 服务(job.schedule 抛出) 唤醒 job 没排上;#4632

后三处的严重性和 #5661 的第 2、3 条是同一档:pnpm check:durability-log-level 扫的 24 个耐久性接缝里就包含 rearmSuspendedWaitTimers,而这三条记录的存在理由就是可读性 —— 文本自己写着「every wait/approval paused before this restart will hang indefinitely」。一条被搅烂的耐久性告警恰是运维最需要能 grep 到的(#4632)。

与 #5661 的关系,以及为什么单独立单而不是子任务

#5661 的范围是 plugin.ts 三处,正文明确列出「刻意不含的两处」,wait-node.ts 根本不在其视野内 —— 它是 plugin.ts 那个 catch 被调用方内部的记录。两单没有依赖关系:#5661 已经落地,这五处照旧。所以按 objectstack#4949 的规矩独立立单,不作子任务。

同族已闭:#5048 / PR #5572(flow 绑定四+一)、#5575 / PR #5639(fail() 两处 + ObjectLogger 三参分派)、#5636 / PR #5662(degradeConnectorInstance 两处)、#5661(plugin.ts 三处)。仍开:#5660(engine.ts 的 registerDegradedConnector 自己那条 warn)。

修法(与前四单同源,零新词汇)

复用同包 thrown-cause-diagnostics.ts 的 describeThrownForLog:message 保持单行自足,cause 走 meta。按 Logger 契约选参数位 —— warn(message, meta?) 用第二参,error(message, error?, meta?) 用第三参(第二参传 undefined,否则每条记录都带栈)。新增字段名不得含 key / token / secret / password 子串(#5573)。

wait-node.ts:98 需要单独判断一下:那里的 cause 是 engine.resume() 的错误信封字段而不是抛出值,describeThrownForLog 的入参形状对不上,可能该走 { error: result.error } 直接给 meta。

改完后确认 pnpm check:durability-log-level 仍绿(三处 error 不得降级、不得改成 rethrow),并注意 plugin-startup-log-cause.test.ts 里 fakeDataEngine 的 failProbe 注释:它现在刻意只让 probe 那次读失败,就是为了绕开本单这条记录;本单修好后那条注释可以简化。

可达性

五处 cause 都来自我们不控制文本的地方(数据源驱动、job 服务、engine 的 resume 信封),今天库内的驱动均单行 —— 所以这是 finding 而不是事故报告。第一个包装多行 SDK 错误的驱动/job 实现即撞上,第 323 行尤其(数据库驱动多行错误在生态里常见,上面的实测就是照这个形状造的)。

Activity

  1. os-zhuang
    added
    domain:services
    finding
    on Aug 6, 2026
  2. claude
    removed
    finding
    on Aug 6, 2026

  3. claude commented on Aug 6, 2026

    @claude
    claudebot
    on Aug 6, 2026 – with Claude
    Contributor

    发现分诊轮判级(#4949 纪律):晋级 pm:queue,域 domain:services 保持。

    过时前提检查:origin/main 889ae47 上 packages/services/service-automation/src/builtin/wait-node.ts 仍有 Cause: 拼接式记录(grep 命中 4 处,加正文表列的第五处形态),前提成立;同族的 #5048 / #5575 / #5636 / #5660 / #5661 均已落地,修法模板已确立(外来 cause 落 meta,msg 只留平台自己的句子)。

    晋级理由:落点唯一(单文件五处)、验收判据可机械陈述(该文件不再出现把外来 cause 拼进 msg 的记录)、且其中三处是 #4632 亲自标为 error 的耐久性诊断 —— 正文实测这些记录在 pretty / text 格式(os dev / os serve 默认)下被切成三个物理行、后两行无级别无时间戳,grep ERROR 只捞到不含任何事实的那一行(cloud#971 同形)。这不是观察类:一条运行时诊断在默认日志格式下丢掉全部事实,是今天就能咬到人的可观测性缺陷。

    本评论来自分诊座位 Routine(#5474 试点),不构成认领。

    Generated by Claude Code

  4. claude
    added
    pm:queue
    on Aug 6, 2026
  5. hotlong
    added
    pm:dispatched
    on Aug 6, 2026
  6. hotlong
    self-assigned this
    on Aug 6, 2026

  7. hotlong commented on Aug 6, 2026

    @hotlong
    hotlong
    on Aug 6, 2026 – with Claude
    Contributor

    认领:PM 循环第 1 轮(services 车道)
    会话:session_015a5qkLzpGXhLL2F5gvJ7dD
    分支:claude/issue-5737-wait-node-cause-meta
    Worktree:objectstack-issue-5737
    域:domain:services
    文件面:packages/services/service-automation/src/builtin/wait-node.ts + 复用同包 thrown-cause-diagnostics.ts + plugin-startup-log-cause.test.ts(注释简化)+ 新增/调整用例
    串行约束已清:今日 58ffcab(#5760)已触该文件,基于合并后 origin/main;同包无其它在飞(#5660 是 engine.ts,另单另轮)

    Generated by Claude Code

  8. hotlong commented on Aug 6, 2026

    @hotlong
    hotlong
    on Aug 6, 2026 – with Claude
    Contributor

    验收:ACCEPT → PR #5911(CI 23/23 绿,随后转 ready 入队,本座位跟到 MERGED)。

    经办:services 座位,会话 session_015a5qkLzpGXhLL2F5gvJ7dD(第 1 轮)。

    Generated by Claude Code

  9. hotlong
    closed this as completedin #5911on Aug 6, 2026
  10. akarma-synetal
    added a commit that references this issue on Sep 17, 2026

    fix(automation): refuse a wait node whose `timerDuration` yields no w…

    bce5270
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

domain:servicespm:dispatchedpm:queue

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions