Rust + WASM の x86 エミュレータで ELKS のテトリスが即ゲームオーバーになる — 犯人は HLT 早送りの時間会計だった

16bit

自作の x86 エミュレータ rustx86 (Rust + WebAssembly、ブラウザで 16bit UNIX や 32bit Linux が動く) で、ELKS 0.9.1 のテトリスを起動すると駒が一瞬で積み上がり、Bye! Your score: 0 と表示されて即終了する。操作する暇は 1 秒も無い。

今回はこのバグの謎解きの記録である。結論から言えば ゲスト OS は無実で、犯人はエミュレータの「時間の会計」 だった。CPU をエミュレートする話ではなく、時間をエミュレートする話をする。

テトリスのテンポはどこから来るか

まず被害者の身元確認から。ELKS のテトリス (elkscmd/tui/ttytetris.c) のメインループは驚くほど素朴で、1 周ごとに駒が 1 段落ちる

while(running)
{
     get_key_event();   /* キーを読む (ここでブロックする) */
     shape_set();
     frame_refresh();
     shape_go_down();   /* 駒が1段落ちる */
}

では 300ms に 1 段のテンポはどこにあるかというと、get_key_event() の中の getchar()、つまり read(2) のブロックそのもの である。初期化時に setitimer で 300ms のワンショットタイマを装填し、SIGALRM ハンドラが自分でタイマを再装填する。

case SIGALRM:
     signal(SIGALRM, sig_handler); /* ELKS requires signal() every signal */
     tv.it_value.tv_usec -= tv.it_value.tv_usec / 3000;  /* 徐々に加速 */
     setitimer(ITIMER_REAL, &tv, NULL);
     break;

キーが来なければ read は 300ms 後の SIGALRM に切られて EOF/EINTR で戻り、ループが 1 周して駒が 1 段落ちる。キーが来ればすぐ戻って操作が反映される。つまり:

read のブロックが 300ms 続くこと、それ自体がゲームのテンポである。

テトリスのテンポ = read(2) がブロックする300ms

逆に言うと、read が待たずに即返りすれば、ループは CPU 速度で空転し、駒は目にも留まらぬ速さで落ちる。症状と一致する。当初はここを疑った — rustx86 の tty まわりか割り込み配送が壊れていて、read がブロックしないのではないか、と。

切り分け 1: ゲストは無実だった

エミュレータの強みは、ゲストの全システムコールを外から覗けることだ。ELKS のシステムコールは int 0x80 (AX=番号、BX/CX/DX=引数) なので、CS:IP の指すバイト列が CD 80 になった瞬間にレジスタを記録し、戻り番地に帰ってきたときの AX を見れば、read の呼び出しと戻り値がトレースできる。

// シスコール入口検出: 次に実行される命令が int 0x80 か
let lin = m.cpu.lin(cpu::CS, m.cpu.ip) as usize;
if m.mem[lin] == 0xCD && m.mem[lin + 1] == 0x80 {
    let ax = m.cpu.regs[cpu::AX] as u16;          // シスコール番号
    if ax == 3 && m.cpu.regs[cpu::BX] as u16 == 0 // read(fd=0, ...)
    {
        // 戻り番地 (int の次) を覚えておき、帰ってきたら AX が戻り値
        pending.push((m.cpu.sregs[cpu::CS], m.cpu.ip.wrapping_add(2), ax));
    }
}
m.step();

これをヘッドレス (ネイティブビルド、ブラウザ無し) で回した結果がこれだ。

[   6910.1ms] syscall 71 呼出 bx=0 ...     ← setitimer(ITIMER_REAL, 300ms)
[   6910.1ms] read ->     -4 (前回から 300.0ms)
[   7210.1ms] syscall 48 -> 0              ← signal(SIGALRM) 再登録
[   7210.1ms] syscall 71 -> 0              ← setitimer 再装填
[   7210.1ms] read ->     -4 (前回から 300.0ms)
[   7510.1ms] read ->     -4 (前回から 300.0ms)

完璧である。 read は仮想時間でぴったり 300.0ms ブロックし、-EINTR (-4) で戻り、SIGALRM → signal(48)setitimer(71) の再装填が寸分の狂いなく回っている。tty も、シグナル配送も、itimer も、全部正しい。

ここで容疑者リストが一変する。ゲスト側の経路 (tty read / SIGALRM / 8042) は全員アリバイ成立。なのにブラウザでは駒が即落ちる。 違いはゲストではなく、「エミュレータの回し方」にしかない。

切り分け 2: ブラウザの回し方を模すと再現した

ブラウザ側 (machine.js) は 60fps のフレームループでエミュレータを回す。ゲストの時計を実時間に繋ぎ止めるため、1 フレームの予算 = 実時間で流れた時間ぶんの仮想時間 としている。

// 予算 = 前のフレームから実時間で流れたぶんの仮想時間
const dt = Math.min(50, now - this.lastFrame);
const budget = Math.round(dt * INSTR_PER_GUEST_MS);  // 16.7ms ≒ 127万命令
for (let done = 0; done < budget; done += CHUNK) {   // CHUNK = 6000
  this.emu.run_slice(Math.min(CHUNK, budget - done));
  // …画面の差分チェック…
}

done += CHUNK という勘定に注目してほしい。これは 「run_slice(6000) は仮想時間をきっかり 6000 消費する」という契約 を前提にしている。

この回し方をネイティブで忠実に再現する実験を書いた。60fps × 16.7ms 予算 × CHUNK=6000 刻み。1 フレームで実際に流れた仮想時間を測る。

frame  0: 予算 1275272 に対し実消費 120947171 ( 94.8倍)
frame  1: 予算 1275272 に対し実消費 126765568 ( 99.4倍)
frame 59: 予算 1275272 に対し実消費 162657024 (127.5倍)
== 60フレーム (実時間1秒ぶん) で流れた仮想時間: 115.9秒 (116倍速)
== 画面: Bye! Your score: 0

再現した。 予算 127 万のフレームが 1.2 億を消費している。実時間 1 秒のつもりが、ゲストの中では 116 秒。read はちゃんと仮想時間 300ms ブロックしているのに、その 300ms が実時間の 2.6ms で流れてしまう。駒は 1 秒に 380 段落ちる。即ゲームオーバーの正体はこれだ。

犯人: アイドル早送りが予算を飛び越えていた

rustx86 には少し前に入れた最適化がある。ゲスト OS がアイドル (HLT で割り込み待ち) のとき、1 命令ずつ空回りせず 次の PIT タイマパルスまで時計と装置を一気に進める idle_fast_forward だ。シェルで待っているだけの機械がホストの CPU を食いつぶすのをやめるための仕掛けで、これ自体は正しい。

問題は跳躍距離である。ELKS は PIT を 100Hz に設定するので、パルス間隔は 10ms。このエミュレータの勘定では 1 回の早送りで最大 76 万命令分 の仮想時間が飛ぶ。

一方、run_slice の予算は 6000。早送りは予算を知らないので、こうなる。

run_slice(6000) の中:
  step 1回目: HLT中 → idle_fast_forward → 763,640 飛ぶ
  予算チェック: 763,640 >= 6000 → 終了

呼ぶ側の勘定:  done += 6000        (頼んだ分だけ進んだはず)
実際:          仮想時間 763,640 経過 (127倍の超過)

フレームループは予算を使い切るまで run_slice を 212 回呼ぶ。アイドル中はその 1 回 1 回が 10ms ずつ 飛ばすので、16.7ms の実時間で仮想 2 秒が流れる。ゲストの時計だけが百倍速で回る。

run_slice の会計 — アイドル早送りが予算を飛び越える

なぜ sl (SL 蒸気機関車) は無事だったのか

面白いのは、同じくタイマ駆動の sl はほぼ実時間で走っていたことだ。これがデバッグを混乱させた — 「時計は正常」に見えたのだから。

種明かしは、rustx86 に 時間の釣り合いを取るランナーが 2 流派ある ことだった。

流派 使う機械 会計方法 早送りの超過
sleep 方式 Linux 機 (Worker) 飛ばした量 (take_idle_skipped) を読んで、その分だけ実時間で sleep 帳尻が合う
予算方式 16bit 機 (メインスレッド) 予算=実時間ぶんの仮想時間を渡し、「頼んだ分だけ進んだ」と勘定 直撃

sleep 方式は「飛びすぎた量」をそのまま待ち時間に変換するので、超過しても事後精算で釣り合う。予算方式は前払い制なので、超過した瞬間に会計が破綻する。同じバグがあっても、片方の流派だけが発症する — 「正常に見える隣人」がいたせいで、時計そのものを疑うのが遅れた。

直し方: 早送りに「予算」を教える

修正は素直で、早送りが予算を超えないようにする。飛んでいる途中で予算が尽きたら、パルスの手前で止まる。残りは次の呼び出しが続きから飛ぶので、パルスは正しい仮想時刻に出る。

fn idle_fast_forward(&mut self, budget: u64) {
    // ...
    // クロック → tick数 (切り上げ)。パルスが出る tick まで飛ぶ
    let to_irq = clocks.div_ceil(PIT_CLOCKS_PER_TICK).max(1) as u64;
    // 予算内に収まる tick 数。最低1 tick は進める — ゼロだと進捗が無く
    // run系のループが空回りする (超過は高々 tick_countdown ≦ 64命令分)
    let affordable = if budget <= self.tick_countdown as u64 {
        1
    } else {
        1 + (budget - self.tick_countdown as u64) / INSTRUCTIONS_PER_TICK as u64
    };
    // 予算が先に尽きるならパルスの手前で止まる。IRQは出ないので機械は
    // 寝たままだが、それでよい — 次の呼び出しが続きから飛ぶ
    let ticks = to_irq.min(affordable) as u32;
    // ...
}

API は step_budgeted(idle_budget) を新設し、従来の step() は「無制限」の別名として残した。1 命令だけ進めたいデバッガなどは従来どおり、予算の中で回る run 系だけが残り予算を渡す。

/// 1命令進める。アイドル早送りは無制限 (次のPITパルスまで一気に飛ぶ)
#[inline]
pub fn step(&mut self) {
    self.step_budgeted(u64::MAX);
}

/// 1命令進める。HLT中の早送りは idle_budget (仮想時間の残り予算) までに制限する
pub fn step_budgeted(&mut self, idle_budget: u64) { /* ... */ }
// run() / run_slice() のループ
loop {
    let elapsed = self.cpu.tsc.wrapping_sub(start);
    if elapsed >= budget {
        break;
    }
    self.step_budgeted(budget - elapsed);  // 残り予算を渡す
}

JS 側 (machine.js / linux-worker.js) は 一行も変えていない。「run_slice(n) は n だけ消費する」という契約をコア側が守るようになったので、呼ぶ側の勘定はそのままで正しくなる。

検証: 会計は合ったか

同じスライス刻み実験を修正後に回す。

frame  0: 予算 1275272 に対し実消費 1278499 (1.0倍)
frame 59: 予算 1275272 に対し実消費 1278720 (1.0倍)
== 60フレーム (実時間1秒ぶん) で流れた仮想時間: 1.0秒 (1倍速)

[  283.8ms] read -> 0     ← 300msごとに正確に戻る
[  583.8ms] read -> 0
[  883.8ms] read -> 0
== read戻り 16 回 / IRQ0 502 回 (期待: 5秒で500回)
項目 修正前 修正後
スライス刻みでの予算消費 88〜127 倍 1.00 倍
実時間 1 秒で流れる仮想時間 116 秒 1.0 秒
read の戻り間隔 (仮想時間) 300.0ms
IRQ0 (PIT 100Hz) 5 秒で 502 回
ブラウザ体感 即積み上がり → Bye! 通常テンポで落下

再発防止には回帰テスト elks_tetris_tempo を追加した。ELKS を実際にブートして root でログインし、テトリスを起動し、machine.js のスライス刻みを忠実に模しながら SIGALRM のテンポを数える。仮想 3 秒で 10 回前後になるはずのアラームが範囲を外れたら落ちる。

// 300ms周期 (SIGALRMごとに0.1ms短縮) なら3秒で10回前後。
// 大きく外れたら時計の会計がずれている
assert!(
    (6..=20).contains(&alarms),
    "3秒でSIGALRM {alarms}回はテンポが狂っている (期待 ~10回)"
);

このテストが本当に事件を検出できるかも確かめた。クランプを一時的に外して走らせると、きちんと「tetris が即死した (時計が速すぎる)」で落ちる。OS 起動回帰 (ELKS・FreeDOS・Linux の 3 OS がプロンプトに到達するか) も全緑である。

教訓

  1. 「時間を飛ばす」最適化は、飛ばした時間の会計を呼ぶ側と揃える。 早送り自体は正しくても、「頼んだ分だけ進む」という契約を破った瞬間に、呼ぶ側の時計が壊れる。契約はコメントではなくコードで守らせる (予算を引数で渡す)。
  2. 同じ時計を見るランナーが複数流派あると、片方だけ発症する。 sleep 方式 (事後精算) は超過を吸収し、予算方式 (前払い) は直撃した。「隣は正常だから時計は無実」という推論は、隣が別の会計方法を使っていたら成立しない。
  3. ゲストのシステムコールを覗けるのはエミュレータ屋の特権。 strace をゲストに入れなくても、int 0x80 の入口と戻り番地を見張るだけで「read が仮想時間 300.0ms ぴったりブロックしている」ことを数字で言い切れた。ゲスト無実の証明が 30 分で終わったのはこれのおかげである。

修正は PR #39 に、経緯の詳細はそのまま PR 本文に残してある。ブラウザで動く実物は rustx86 のリポジトリ からどうぞ — ELKS を起動して root でログインし、tetris と打てば、今度はちゃんと遊べるテンポで駒が落ちてくる。

コメント

タイトルとURLをコピーしました