ci,test: a #4250 stall now names its own culprit; objectql test kernels stop intercepting worker SIGTERM - #4341
Merged
Conversation
…ntercepting SIGTERM (#4250) Investigation results behind this change (full analysis on #4250): - Both stall-point files sit in packages/objectql, but neither the in-test drivers (pure in-memory no-ops) nor bare ObjectQL engines hold event-loop handles, lifecycle sweep timers are unref'd, and the logger is threadless -- the issue's unreleased-handle hypothesis does not fit this package's unit suites. - What DID show up: one objectql run booted 47 kernels whose gracefulShutdown default installed SIGINT/SIGTERM/SIGQUIT handlers inside vitest fork workers -- 48 SIGTERM interceptions per run, every worker recycle running a multi-kernel async shutdown race (3 of 47 graceful shutdowns never completed, cut short by another kernel's process.exit). Every path does eventually exit, so this is not proven to BE #4250 -- but it is the machinery standing closest to it, and it serves no test purpose. - Those same kernels declared `logLevel: 'silent'` -- a config key ObjectKernelConfig never had (the real shape is `logger.level`; CI type-checks spec and examples, not these tests, which is why the dead key survived). All 47 boots logged at info: ~half the package's log volume, the exact "engine init sequences" frozen at the top of both #4250 logs. Changes: - plugin.integration.test.ts / plugin.step2.test.ts: kernels boot with the real silence key (`logger: { level: 'silent' }`) and gracefulShutdown:false, and afterEach shuts down what it booted. Verified: kernel bootstrap log lines in a full run drop 47 -> 0, worker SIGTERM interceptions 48 -> 0, package log 4579 -> 2096 lines, 87 files / 1374 tests stay green. - run-with-stall-guard.mjs: on a declared stall, before killing, it now (1) samples every process in the frozen group twice via /proc and classifies each as ON-CPU (sync spin / GC thrash) or idle (awaiting something that never settles), and (2) with --report-dir set, sends SIGUSR2 so every node process whose event loop is alive dumps a diagnostic report -- digested into the log as an exact JS stack; a process that produces NO report is named as loop-blocked (verified behavior: node's report-on-signal is served by the event loop). Forensics are Linux-/proc best-effort, add at most ~6s before the kill, and never fail the kill path. - ci.yml: Test Core and Dogfood test steps arm the harvest via NODE_OPTIONS (--report-on-signal) and pass --report-dir; on failure the full reports upload as artifacts (14-day retention). The next real stall stops being a mystery: the step log will say which process froze, in which mode, and -- for the await-forever class -- on exactly which stack. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_014NNaWXVEyG6Pv4EFRfYGg6
|
The latest updates on your projects. Learn more about Vercel for GitHub. 1 Skipped Deployment
|
github-actions
Bot
added
size/m
documentation
Contributor
📓 Docs Drift CheckNo hand-written docs reference the 0 changed package(s). ✅ |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
#4250 根因排查的落地 PR。完整分析随后贴在 issue 上;这里是结论对应的改动。
排查结论(细节见 #4250 评论)
ObjectQL引擎不持有事件循环句柄、lifecycle 定时器全部 unref、logger 无线程。gracefulShutdown默认值在 vitest fork worker 里注册 SIGINT/SIGTERM/SIGQUIT 处理器 —— 实测每轮 48 次 SIGTERM 截获,每次 worker 回收都在跑多 kernel 并发异步停机竞赛(47 次 graceful shutdown 有 3 次没跑完,被别的 kernel 的process.exit截断)。理论上每条路径最终都会 exit,所以不能断言这就是 CI:Test Corestalls mid-suite with frozen log output — three occurrences in one day, each costing a manual diagnosis + rerun #4250;但它是离事故最近的机器,且对测试毫无价值。logLevel: 'silent'在ObjectKernelConfig上从未存在过(真实形状是logger.level;CI 的 typecheck 只覆盖 spec 和 example apps,测试文件不在内,所以死键一直活着)。47 个 kernel 全程 info 级输出 —— 正是两次停摆日志顶部反复出现的"引擎初始化序列"。改动
plugin.integration.test.ts/plugin.step2.test.ts(objectql)logger: { level: 'silent' }+gracefulShutdown: false,并在 afterEach shutdown 自己 boot 的 kernel。run-with-stall-guard.mjs停摆取证(杀进程之前)/proc采样(2 秒间隔),逐进程分类:ON-CPU(同步自旋 / GC 抖动)vsidle(等待永不 settle 的东西);--report-dir:向组内 node 进程发 SIGUSR2,事件循环存活者会写出诊断报告(精确 JS 栈 + libuv 句柄),摘要进日志;不出报告本身就是判词(已实测验证:report-on-signal 由事件循环服务,同步阻塞进程必然沉默)——配合 CPU 分类即可定位冻结者与冻结类型;/proc、全程 try/catch、最多让 kill 晚 ~6 秒,绝不影响杀进程路径。ci.ymlNODE_OPTIONS=--report-on-signal ...武装全部 node 进程,guard 传--report-dir;验证
[R->R] cpuΔ=200被判 ON-CPU 且无报告、空转者[S->S] cpuΔ=0出报告,分类与收割全部正确;效果
下一次 #4250 停摆的 step 日志会直接写明:哪个进程冻结、哪种冻结模式、(await 型)冻在哪个栈上 —— 从"要人工判读的谜题"变成"自带答案的红"。
ref #4250、#4309、#4316。不关闭 #4250 —— 等下一次停摆的取证数据落地后再收口。
🤖 Generated with Claude Code
https://claude.ai/code/session_014NNaWXVEyG6Pv4EFRfYGg6
Generated by Claude Code