Repository navigation
[PR] fix: stamp bili.log lines with the system local time | 日志时间改用系统本地时间 - #4537
yanhuojiyusheng wants to merge 1 commit into
Conversation
ae921a1 to
d3e419f
Compare
(ai: vllm-qwen/qwen3.8-27b) 查重: 不重复。检索 open/closed issue 与近期 PR 均无同主题条目(#4535 是本 PR 的源 issue,同作者、先于本 PR 7 分钟)。 标签: bug, p3, scope/ui(已打,连同原有 pr)——纯日志可读性缺陷,无功能/数据影响(p3);观察面在面板日志视图与人工排查(scope/ui);也是你在 #4535 里请求的标签。 审核结论(结构化八问)
review 中发现的两处小修(已写好,附补丁)
- * Line format: `<iso-ts> [level][ [sess=<session-id>]] [v=<version>] <msg>`
- * — one prefix per PHYSICAL line (multi-line payloads repeat ts+level+tags on
- * every row, which is what makes line-wise grep / time-window queries honest).
+ * Line format: `<local-ts> [level][ [sess=<session-id>]] [v=<version>] <msg>`
+ * (`<local-ts>` = the system's local wall clock without a zone suffix — see
+ * logTimestamp(); pre-#4535 lines carry a UTC `Z` stamp, readers must accept
+ * both since one file outlives the format change). One prefix per PHYSICAL
+ * line (multi-line payloads repeat ts+level+tags on every row, which is what
+ * makes line-wise grep / time-window queries honest).
test("bare stamps are LOCAL time end-to-end (TZ forced, non-whole-hour offset)", () => {
if (process.platform === "win32") return; // process.env.TZ is only honored on POSIX
const prevTz = process.env.TZ;
try {
process.env.TZ = "Asia/Kathmandu"; // UTC+05:45 — non-whole-hour offsets catch sloppy math
const instant = Date.UTC(2026, 9, 24, 11, 0, 0); // 16:45:00 Kathmandu wall clock
const ts = logTimestamp(new Date(instant));
assert.equal(ts, "2026-10-24T16:45:00.000"); // writer emits LOCAL fields, no suffix
assert.equal(Date.parse(ts), instant); // bare stamp reads back as LOCAL → same instant
} finally {
if (prevTz === undefined) delete process.env.TZ; else process.env.TZ = prevTz;
}
});两个 commit 我已在本机基于你的 head 做好并跑过(该文件 4/4 绿、typecheck/build 绿),但 push 被拒:fork 不允许我推分支,且 PR 没开 "Allow edits by maintainers"(maintainer_can_modify=false)。请二选一:① 把上面两段按原样提交到你的分支;② 在 PR 设置里勾上 Allow edits by maintainers,我来推。 本地验证(PR head d3e419f)
CI 状态(需注意)PR head 上 47 个 check-run:28 success / 12 skipped / 7 failure,失败的 7 个全是
这两条路径本 PR 一行没碰,且这两个测试文件我在 PR head 本地全绿(10/10);同时 master 自己最新的 CI 也有红(lifecycle-ledger-guard、deploy)。判断:环境性/既有问题,不是本 diff 引入的回归。建议重跑失败的 test 分片;若重跑后同一签名仍在,我再单独立项跟踪(暂不为单次疑似 flake 开 issue)。另:PR 描述说"master docs-sync 为红、test 矩阵会被 needs 跳过"已过时——本 PR head 上 docs-sync 是绿的,test 矩阵实际跑了。 收工判定方向正确、根因定位准确、diff 干净、行为变更披露完整、配置面无新增、review 未发现意外回归;两处小修(见上)落进分支 + 失败分片重跑转绿后即可合并。合并动作按规矩由你/owner 执行。 |
01e0b46 to
28f9402
Compare
Review follow-up on top of #4537: local-time stamping landed in src/logger.ts only, but three more writers emit the same line head into the same paste-able log surface and would keep writing UTC Z stamps after merge: - src/agent/host-log.ts — [dsh-client]/[native-client] host-side events share bili.log with proxy-side lines (#3651) - src/server.ts writeSpawnPortLog (x2) — per-port temp log on listen failure - src/launcher.ts defaultAttachDiag — debug stderr copy of attach diagnostics All four now use the shared logTimestamp(). The five test assertions pinning the old Z head for these writers are updated to pin the bare-local head, and tests/logger-local-time.test.ts gains a mixed-generation window test (legacy Z rows + new bare rows in ONE array) pinning the compat promise that a rotated file outlives a format change.
|
(ai: vllm-qwen/qwen3.8-27b) 审核结论:方向正确、核心实现成立,质量达标(测试是确定性构造、不靠环境运气,正则放宽最小、注释讲清了为什么)。但有 4 处同机制的写入点漏改——合入后 #4535 的症状会在这些行上继续存在。我已把补齐做成一个 additive commit(见文末),等你解锁推送或自行 cherry-pick。 八问:
我补的 4 处漏改(同一机制:相同的行首语法、同一个可粘贴日志面,却仍在写 UTC):
commit 位置与落地方式:
另外两点状态说明:PR base 略落后当前 master(无冲突,mergeable);你正文提到的 docs-sync 红在最新 master 已恢复绿,CI 测试矩阵会正常跑。合并由人来操作,我不代合。 |
28f9402 to
186f485
Compare
(ai: vllm-qwen/qwen3.8-27b) 收到这条补充 review。我按规矩没有直接采信,把每处写入点和 commit 先纠错(诚实作答)我上一轮回复里写「host-log / spawn-port / launcher 是独立文件/独立格式,有意不动,正确」——对 host-log 这一处我判错了。实际代码: 逐处复核结果(均独立读码确认):
对
|
(ai: vllm-qwen/qwen3.8-27b) 结论:本 PR 的 CI 红是继承自 master 的存量红灯,与日志时间戳改动无关。未向分支推送任何代码——等 master 修绿后 rebase 重跑即可。 证据(本地三提交对照复现) 把 CI 失败涉及的全部 8 个测试文件在三个提交上各跑一遍:
所有失败项在本 PR 提交之前就已存在 → 日志时间戳改动完全免责;本 PR 新增的 失败项清单(去重后)
为什么之前没暴露:master 自 10-24 16:21Z(#4590 合并后)gate job( 八问
已按 #4599 纪律在那边留了一行记录。判定:暂不合,等 master 绿后 rebase。 |
(ai: vllm-qwen/qwen3.8-27b) 重复通知(同一 run 40105194164、head 186f485):状态无变化——本 PR 无新提交无新运行,红的仍是同一批继承自 master 的 17 项。判定见上方评论(三提交本地对照复现,与 logger 改动无关),#4599 总控已留记录。master 侧进展:gate job( |
d03ada6 to
ad1df2d
Compare
bili.log 每行都用 `new Date().toISOString()` 打戳:永远是 UTC 并以 Z 结尾, 而系统时钟(`date` / timedatectl)给的是本地时间。排查时两者差着整个时区 偏移(本机 CST 是 8 小时),日志里刚发生的事件看起来像是几小时前,必须 手工换算才能和终端、浏览器、宿主日志对齐。 - `logTimestamp()` 输出本地墙上时间 `YYYY-MM-DDTHH:mm:ss.SSS`(无后缀), 与 `date` 逐字对齐;两处打戳点(file+stderr 与降级 warn)统一走它; - 读侧兼容:该格式没有时区标记,历史日志里全是 `Z` 结尾,`logs-query` 的 时间窗过滤与 `acp-cache-diff` 的 usage 行解析都放宽为"时区段可选", 同一文件里新旧两种戳都能解析(裸戳按本地时间解释); - 测试:格式与本地字段、`Date.parse` 回环、新旧混合时间窗、usage 行解析。 验证:定向 suite 49/49、`npm run typecheck`、`npm run build`(dist 导入与 外部依赖检查 OK);时区矩阵(Shanghai/UTC/New_York/Kathmandu +05:45/ St_Johns -02:30)日志与 `date` 同刻;真实 `dist` 起代理在隔离 XDG 下三个 时区 e2e,日志文件时间与系统时间一致。全量回归以远程 CI 为准。
ad1df2d to
63fcf8d
Compare
|
closing as superseded by #4798 (merged): your head 63fcf8d cherry-picked + the reviewed followup b64e160 (host-log / writeSpawnPortLog / launcher stderr writers + the 5 pinned Z assertions + mixed-format window test). your branch is not maintainer-editable, so the completion landed as a maintainer branch with full credit in the PR body. thanks for the report and the fix — the local-time bili.log is now internally consistent. |
Fixes #4535
问题
bili.log的打戳点用new Date().toISOString():永远是 UTC 且以Z结尾,而系统时钟给的是本地时间。本机(Asia/Shanghai)同一瞬间日志2026-10-24T11:19:02.681Zvsdate19:19:02 +0800—— 排查时每次都得手工折算,日志里的“刚刚”看起来像几小时前,和终端、宿主日志、面板其它字段(走toLocaleString())不同基准。时钟本身是准的:探针请求 UTC
11:19:02.673写出行11:19:02.681Z(8 ms),文件 mtime 与最后一行对应同一瞬间。方案
src/logger.ts新增logTimestamp():输出系统本地墙上时间YYYY-MM-DDTHH:mm:ss.SSS(无后缀),与date逐字对齐;两处打戳点(log()的 file+stderr 行、warnReopenFailed()的降级 warn 行)统一走它。src/web/logs-query.ts的TS_RE与src/acp-cache-diff.ts的 usage 行正则都把时区段改为可选 —— 新裸戳按本地时间解释,历史/rotated 文件里的Z行仍按 UTC 解释,同一文件两种都能解析。tests/logger-local-time.test.ts:格式与本地字段、Date.parse回环、新旧混合的时间窗过滤、usage 行解析。行为变更披露(有意)
Z行保持原样,不重写、不迁移;新行不再带任何时区标记,因此把日志带到别的时区时无法判断归属(这是本 PR 接受的可读性代价,见 Timestamps in bili.log are always written in UTC, which differs from the system local time by the full timezone offset ( | bili.log 时间戳固定写 UTC,与系统本地时间差整个时区偏移(排查需手工折算) #4535 的讨论)。Z)。验证
date):Asia/Shanghai19:40:29、UTC11:40:29、America/New_York07:40:29、Asia/Kathmandu(+05:45)17:25:29、America/St_Johns(-02:30)09:10:29—— 全部一致。npm run build后node dist/index.js start在隔离 XDG 下跑 Kathmandu / St_Johns / UTC 三个时区,bili.log时间与系统时间同刻。queryLogLines时间窗,命中行数 >1(证明解析成功,否则会退化成只返命中行)。node --import tsx --test tests/logger-local-time.test.ts tests/web-logs-query.test.ts tests/web-logs-view.test.ts tests/acp-cache-diff.test.ts tests/logger-{rotate,rotation,session-tag,silent-loss,epipe,stderr-mute}.test.ts→ 49/49。npm run typecheck通过;npm run build通过(dist-import-annotations: OK/dist-external: OK)。docs-sync为红(种子缺pluginLaneServerHistory),与本 PR 无关,test 矩阵会被needs跳过。配置面
无新增/重命名/语义变更的配置项:时区来源就是系统时区,没有新 env、没有新 config 字段,
CONFIGURATION.md无需改动。