6.3 断言、遥测与线上问题定位
6.1 让引擎把状态画出来,6.2 让开发者能敲命令改状态——这两样都假定你坐在机器前。但最需要定位的问题往往发生在你看不到的地方:玩家报了个崩溃,日志里只有一行「something went wrong」。这一节补上最后一层保障:让引擎在无人值守时也能把现场留住。
三个组件缺一不可:断言告诉你「哪里不该发生的事发生了」;遥测记录「发生前后引擎在干什么」;崩溃快照在致命错误的一刻把前两者冻结下来。它们合起来,才能把一次线上崩溃还原成一条可读的时间线。
断言分级与剥离
第一层的规则在第一卷就定了,这里只是把它讲透。diagnostics.ts 里有两个入口:assert 只在 debug 档生效,release 构建里整句被剥掉;check 在任何构建档都生效,是真正的致命检查。
// snippet: src/core/diagnostics.ts 的两级断言
/** debug 专属断言;release 下直接返回不抛错。 */
export function assert(condition: boolean, message: string): void {
if (buildMode === 'debug' && !condition) throw new AssertionError(message);
}
/** 所有构建档都生效的致命检查。 */
export function check(condition: boolean, message: string): void {
if (!condition) throw new AssertionError(message);
}
分级的判据不是「重不重要」,而是「修复它的成本」。debug 档能复现的内部一致性检查——比如「矩阵的行列式不该是 0」「实体句柄的世代号必须匹配」——用 assert;这些检查在正式档里既昂贵又无法补救,剥掉它们换来的是干净的产物。而「显存分配失败」「必需资源 404」这类不处理就必然崩的条件用 check:它必须在正式档也拦下来,给上层一个体面退出的机会。
需要点破一个陷阱:TypeScript 没有宏,assert 的 condition 是普通实参,调用点仍会求值它一次。所以 assert(hashMap.has(k), ...) 这种写法里,has 的调用在 release 档照样发生。真正想省掉的,是把结果算好再传进来:
// snippet: 计算昂贵时先算再断言,release 下这段计算仍会执行
const ok = expensiveInvariantCheck(world); // 无副作用时才会被死代码消除
assert(ok, 'world invariant broken');
所以 assert 只适合「检查本身廉价」的场合;昂贵的一致性校验要放到专门的 debug 系统里,由特性开关整块裁掉,而不是靠一句 assert。
把三种手段摆在一起,各自的位置就清楚了:
| 手段 | 生效档 | 失败行为 | 适用场景 |
|---|---|---|---|
assert | 仅 debug | 抛 AssertionError | 廉价、能在开发期复现的内部一致性检查 |
check | 所有档 | 抛 AssertionError | 不处理就必崩的致命条件(分配失败、资源缺失) |
Logger.warn/error | 所有档 | 只记一条日志 | 可疑但可继续的情况(降级、回退、超时重试) |
判据只有一条:这个问题现在能不能修。能修、修完就不用再花代价检测的,用 assert;不能修、正式档也必须拦的,用 check;拦不住也不该拦、只需要留证据的,用日志。三级混用的典型症状是「正式档里一句 assert 悄悄没了,于是崩溃点从有信息的位置挪到了几百行之后的空指针解引用」。
可运行产物:遥测采样与崩溃快照
遥测的核心是一组计数器加一条事件环形缓冲。计数器无论采样与否都精确累加——它是「事实」,不能被采样掉;事件则按固定步长采样后进缓冲,只保留最近 cap 条,避免长时间运行时把内存吃光。
// file: src/core/telemetry.ts
// tier: L1
// verify: npx vitest run src/core/telemetry.test.ts
//
// helio 内核:遥测与崩溃上下文。三件事:
// 1) 计数器:无论采样与否都精确累加(它是「事实」,不能被采样掉);
// 2) 事件:按固定步长采样后进环形缓冲,只保留最近 cap 条;
// 3) 崩溃快照:出致命错误时把环形缓冲 + 计数器一起冻结,事后能重建现场。
//
// 采样是「确定性」的:第 seq 条事件当且仅当 seq % sampleEvery === 0 时被记录。
// 不用随机数,是为了让同一次复现跑出同一条时间线。
import { assert } from './diagnostics.ts';
export interface TelemetryEvent {
readonly seq: number;
/** 虚拟时间(毫秒),由调用方给,不读系统时钟——否则复现不出来。 */
readonly t: number;
readonly name: string;
readonly fields: Readonly<Record<string, number | string>>;
}
export interface CrashSnapshot {
readonly reason: string;
readonly events: readonly TelemetryEvent[];
readonly counters: Readonly<Record<string, number>>;
readonly stats: {
readonly emitted: number;
readonly recorded: number;
readonly dropped: number;
};
}
export class Telemetry {
readonly #cap: number;
#sampleEvery: number;
readonly #events: TelemetryEvent[] = [];
readonly #counters = new Map<string, number>();
#seq = 0;
#emitted = 0;
#recorded = 0;
constructor(cap = 64, sampleEvery = 1) {
assert(cap > 0, `telemetry cap must be > 0, got ${cap}`);
assert(sampleEvery >= 1, `telemetry sampleEvery must be >= 1, got ${sampleEvery}`);
this.#cap = cap;
this.#sampleEvery = sampleEvery;
}
/** 采样步长:N 表示每 N 条事件记一条。 */
setSampleEvery(n: number): void {
assert(n >= 1, `sampleEvery must be >= 1, got ${n}`);
this.#sampleEvery = n;
}
get emitted(): number {
return this.#emitted;
}
get recorded(): number {
return this.#recorded;
}
get dropped(): number {
return this.#emitted - this.#recorded;
}
/** 计数器永远精确累加,与采样无关。 */
count(name: string, by = 1): void {
this.#counters.set(name, (this.#counters.get(name) ?? 0) + by);
}
counter(name: string): number {
return this.#counters.get(name) ?? 0;
}
/**
* 记一条事件;被采样丢弃时返回 false。
* `always=true` 的事件绕过采样——错误、状态迁移这类关键事件一条都不能少。
*/
event(name: string, fields: Record<string, number | string> = {}, t = 0, always = false): boolean {
this.#emitted++;
const seq = this.#seq++;
if (!always && seq % this.#sampleEvery !== 0) return false;
this.#recorded++;
this.#events.push({ seq, t, name, fields });
if (this.#events.length > this.#cap) this.#events.shift();
return true;
}
/** 冻结现场:最近 cap 条事件 + 全部计数器 + 采样统计。 */
snapshot(reason: string): CrashSnapshot {
return {
reason,
events: [...this.#events],
counters: Object.fromEntries(this.#counters),
stats: { emitted: this.#emitted, recorded: this.#recorded, dropped: this.dropped },
};
}
}
/** 把快照里的采样事件重建成一行行可读时间线。 */
export function timeline(snap: CrashSnapshot): string[] {
return snap.events.map((e) => {
const kv = Object.entries(e.fields)
.map(([k, v]) => `${k}=${v}`)
.join(' ');
return `#${e.seq} t=${e.t}ms ${e.name}${kv.length > 0 ? ` ${kv}` : ''}`;
});
}
/** 致命错误:先冻结快照,再抛出带着快照的异常,调用栈与现场一起带出去。 */
export function fatal(t: Telemetry, reason: string, message: string): never {
const snap = t.snapshot(reason);
const err = new Error(`${message} [${reason}]`) as Error & { snapshot?: CrashSnapshot };
err.snapshot = snap;
throw err;
}
两处设计值得单说。时间戳由调用方给,而不是读 Date.now()——系统时钟不可复现,而游戏循环本来就有一个逻辑时间;用虚拟时间,同一次回放才能跑出同一条时间线,这与 helio-eng-02-3 确定性回放回归
是同一个信条。采样用 seq % N 而不是随机数,同样是为了确定性:同样的输入,被记录的事件集合永远相同。
单测盯四件事:计数器不被采样影响、采样步长可调、环形缓冲只留最近 cap 条、fatal 抛出的异常带着快照。关键几条:
// snippet: src/core/telemetry.test.ts 的三条关键断言
it('计数器不受采样影响,永远精确', () => {
const t = new Telemetry(64, 4); // 每 4 条记 1 条
for (let i = 0; i < 10; i++) { t.count('frames'); t.event('tick', { i }); }
expect(t.counter('frames')).toBe(10); // 全部计入
expect(t.recorded).toBe(3); // seq 0,4,8
});
it('关键事件用 always 绕过采样', () => {
const t = new Telemetry(64, 4);
t.event('tick'); t.event('tick');
expect(t.event('asset.fail', { code: 404 }, 0, true)).toBe(true); // seq2,本来会被丢
expect(t.snapshot('x').events.map((e) => e.name)).toContain('asset.fail');
});
it('fatal 抛出携带快照的异常', () => {
const t = new Telemetry(8, 1);
t.count('entities', 3);
expect(() => fatal(t, 'null-handle', 'dangling handle'))
.toThrow(/dangling handle \[null-handle\]/);
});
三个组件怎么配合
单看每个组件都不稀奇,关键在它们如何咬合。assert / check 负责判定「这算不算故障」,遥测负责记录「故障前后发生了什么」,fatal 负责收口「判定为故障的那一刻,把记录冻结」。三者接起来的写法大致是这样:
// snippet: 致命路径的收口——先记事件,再 check,最后 fatal 冻结现场
function loadRequired(asset: string, t: Telemetry): Asset {
t.event('asset.load', { asset }, clock(), true); // 关键事件,绕过采样
const a = tryLoad(asset);
if (a === null) fatal(t, 'asset-404', `required asset missing: ${asset}`);
return a;
}
注意 fatal 之前那条事件带了 always = true。这不是可有可无的细节:如果它跟着普通事件一起采样,恰恰在最需要它的那次崩溃里可能被丢掉。凡是你「事后一定会想看」的事件,都必须绕过采样——采样省的是空间,不是证据。
另一处咬合是「谁触发快照」。快照不该由遥测自己周期性产生(那样内存和 IO 都会失控),而应由 check 失败或 fatal 调用一次性触发。于是正式档的运行成本只有一个定长环形缓冲的写入,出问题时才付一次冻结的代价。
从日志重建现场
最后把整条链跑一遍。模拟《微光岛》跑到第 120 帧时一个必需资源 404,直接致命退出:
$ node tools/telemetry-demo.mjs
reason : asset-404
counters: {"frames":120,"drawCalls":5040,"assetErrors":1}
stats : {"emitted":121,"recorded":25,"dropped":96}
现场时间线(环形缓冲最近 16 条):
#45 t=736ms frame n=45 ms=16
#50 t=816ms frame n=50 ms=16
#55 t=896ms frame n=55 ms=16
#60 t=976ms frame n=60 ms=16
#65 t=1056ms frame n=65 ms=16
#70 t=1136ms frame n=70 ms=16
#75 t=1216ms frame n=75 ms=16
#80 t=1296ms frame n=80 ms=16
#85 t=1376ms frame n=85 ms=16
#90 t=1456ms frame n=90 ms=16
#95 t=1536ms frame n=95 ms=16
#100 t=1616ms frame n=100 ms=16
#105 t=1696ms frame n=105 ms=16
#110 t=1776ms frame n=110 ms=16
#115 t=1856ms frame n=115 ms=16
#120 t=1936ms asset.fail asset=island.glb code=404
三个数字各司其职。counters 给出总量事实:一共 120 帧、5040 次 draw、1 次资源错误——即使 frames 事件被采样丢掉 95%,这个计数一个不差。stats 说明采样代价:121 条事件里记了 25 条、丢了 96 条,缓冲只花 25 条的空间。而 timeline 给出顺序:最后一条 #120 asset.fail 就是致命点,前一条采样帧停在 t=1856ms,两者之间隔了 80ms——不是「崩在启动」,而是「跑到第 120 帧才崩」。
关键事件那行之所以没被采样丢掉,靠的是 always = true:如果它跟着普通帧一起采样,#120 就会是 #119 或别的帧,真正的病因反而消失了。这也解释了为什么 event 要留一个绕过采样的口子——采样是为了省空间,不是为了丢证据。
这套东西的边界同样要说清:环形缓冲只保留最近 cap 条,更早的现场确实没了;fatal 只冻结内存里的快照,把它送出进程(写文件、上报服务端)是宿主环境的责任,不是内核的。真机上的崩溃(原生栈、驱动层错误)也超出这套纯 JS 遥测能覆盖的范围,那属于 L4 内容,需在真实设备上手动验证。
至此,《微光岛》的调试工具箱就齐了:6.1 看得见状态,6.2 改得动状态,6.3 留得住现场。下一章开始真正把游戏做完——从玩法装配开始。
阅读导航:上一节:6.2 控制台与作弊命令 · 下一节:7.1 玩法装配:收集、昼夜、存档 。
继续阅读
探索更多技术文章
浏览归档,发现更多关于系统设计、工具链和工程实践的内容。