/var/log/hdk.log

2017 年 6 月下旬


20 (火)

%1 かようび

朝は整形外科でリハビリテーション。 牽引こんでなかった。

%2 Ryzen General Protection Exception

やっと噂の一般保護例外が出た。 例によって cc1 だがとても楽しいことになっている。

 GPE  flags 00003202 err 00000000 0033:0101356e *
 RAX 00000001    RCX 00000AED    RDX A656C63796320    RBX 012B7050
 RSP 7FFE731E3668    RBP 00000000    RSI 00000007    RDI 015B7AED
 R8  015B7AED    R9  0000007F    R10 00000005    R11 00000007
 R12 7F146FCAB410    R13 7F146FCC0078    R14 015B7AED    R15 7F146FC8C248

表示しているのは VMM 内に自分で追加したテストプログラムなので表示がいい加減なのはそのせい。 とにかく %rip=0x0101356e で一般保護例外だ。 フラグは IOPL=3, IF=1, bit1=1 以外は 0 だ。

[31] cs 33 ip 0101356e sp 7ffe731e3668 code 04d info1 00000000 info2 00000000 (
00b78900 c3ff5fd0/2be81872 85ff56df) br[00c67aee->01013560] ex[7f146ff13828->7f
146ff13860]

これも自分が追加したプログラムによる出力なので意味がわからないと思うが、code 04d が一般保護例外による #VMEXIT を表す。 謎の 00b78900 は Guest Instruction Bytes を出したもので、一般保護例外は対象でないので記録されておらず、下位 4 ビットは 0 になっている。 その後ろの 2be81872 85ff56df のところは、%rip を同じ論理 CPU 上で VMM から読み出したもので、キャッシュが壊れているわけではないことを確かめるためにやってみたものだ。br のところが LastBranchFromIP と LastBranchToIP である。 最後の分岐が 0x00c67aee から 0x01013560 だと言っている。

%rip のところを gdb で逆アセンブルすると以下のように出た:

=> 0x101356e <_Z22private_is_attribute_pPKcmPK9tree_node+14>:
    jb     0x1013588 <_Z22private_is_attribute_pPKcmPK9tree_node+40>
ここまでなら、「条件ジャンプで一般保護例外が出るなんて!」で終わる。 そのまま再開すれば動くんじゃないのとも言いたくなる。 しかし、そうじゃないんだな。 スタックを見てみよう。
0x7ffe731e3668: 0x0000000000c67af3      0x000000fb00000010

0x0000000000c67af3 は 0x00c67aee+5 であり、call 命令のようである。 そこは正しい。 呼び出しもとの call 命令は以下のようにちゃんとある。

 c67aee:       e8 6d ba 3a 00          callq  1013560

なので、分岐の情報は合っている。 じゃ、その先は?

 1013560:       48 83 ec 08             sub    $0x8,%rsp
 1013564:       8b 42 20                mov    0x20(%rdx),%eax
 1013567:       48 39 f0                cmp    %rsi,%rax
 101356a:       75 1c                   jne    1013588
 101356c:       48 8b 72 18             mov    0x18(%rdx),%rsi

一発目にスタックポインターの減算である。 上のスタックダンプを見ての通り、これは実行されていないとしか思えない。 しかも、%rip が指しているのは 4 バイトの mov 命令の 3 バイト目である。 ますますおかしい。

ここで頭をよぎるのが、何度も見ている 0x40 問題。 まさか、このサブルーチンの 0x40 手前に何かあるのだろうか?

 1013520:       48 8b 57 10             mov    0x10(%rdi),%rdx
 1013524:       b8 01 00 00 00          mov    $0x1,%eax
 1013529:       48 85 d2                test   %rdx,%rdx
 101352c:       74 e9                   je     1013517
 101352e:       48 8b 4a 10             mov    0x10(%rdx),%rcx

それっぽい命令が並んでいる。 順に検証しよう。 最初の mov 命令が読み取るメモリーの内容を確認する。

(gdb) x/xg 0x10+$rdi
0x15b7afd:      0x000a656c63796320
(gdb) p/x $rdx
$5 = 0xa656c63796320

完全に一致。 次の mov 命令がセットするレジスターの内容を確認する。

(gdb) p/x $rax
$6 = 0x1

これも完全に一致。 その次の test は上で確かめた %rdx の値に対してで、これを実行すると必ず CF=0, OF=0 になる。 また、%rdx の下位 8 ビットで立っているビットはひとつだから、PF=0 だ。 値はゼロでないので ZF=0 だ。 つまりフラグレジスターの値にも矛盾はない。 当然その次の条件ジャンプはジャンプせず、その次の mov 命令でアクセスすることになるのが %rdx+0x10 番地。 この番地は 48bit の符号付き整数で表せる範囲を超えているので、そこにアクセスすれば一般保護例外が発生する。 そしてこの命令がある番地 0x101352e は、見事に %rip-0x40 だ。 うわぁぁぁ。

さて、これを再開するとしたら、まず、いくつかのレジスターの値を復旧させなければならない。callq 1013560 の直前を見ると %r12->%rdx, %rax->%rsi だったことがわかるので、そこから %r12->%rdx をもう一度と、%rsi->%rax をすれば復旧完了。 あとは %rip=0x1013560 にして再開だ。 予想通り成功した。

そんなわけでね、ここ数日の印象としては、命令デコーダーか何か、その辺がひどく変な感じがする。 命令関係のキャッシュが原因の可能性もありそう。 番地の違うキャッシュをなぜか使っちゃってる、みたいな? そしてそのキャッシュだかなんだかわからないがたぶん 64 バイト単位なのでは。 でも分岐アドレスがズレて記録されていたのもあったな。 あれは何だ。

2017/06/20 のコメントを読む・書く


Powered by Tomsoft Diary System 1.7.4

/var/log/hdk.log コメント一覧

トップ / 日記索引 / 日記 (2017 年 6 月下旬)

Hideki EIRAKU