Slide 1

Slide 1 text

Ryzen SEGV Battle Sep 23 2017 Satoru Takeuchi [email protected] twitter: satoru_takeuchi 1

Slide 2

Slide 2 text

はじめに ● 最新のRyzen 1800X(8core 16 thread)搭載のPCを新調 ● linuxカーネル(defconfig)のビルド速度は1分(先代マシンの5倍高速) 2

Slide 3

Slide 3 text

終わりの始まり ● 何度かカーネルビルドしたらgccがSEGV吐いて死亡 ● 先代マシンでは起きない 3 ./include/trace/perf.h:41:9: internal compiler error: Segmentation fault struct hlist_head *head; \ ^ ... Please submit a full bug report, with preprocessed source if appropriate. See for instructions.

Slide 4

Slide 4 text

容疑者 4 gccやgccが依存するライブラリ Linux kernel ハードウェア 可能性 高 可能性 低

Slide 5

Slide 5 text

検証環境 ● ハードウェア ○ CPU: Ryzen 1800X ○ マザーボード: ASUS PRIME X370-PRO ○ BIOS: 常に最新。設定はSVM有効化以外はデフォルト ■ バージョン: 0504(AGESA1.0.0.4)~0805(AGESA1.0.0.6a) ○ DIMM: Kingston KVR24N17S8/8 * 4 (8 * 4 = 32GB) ■ QVLには載ってないがAMDからOKが出ている ■ Memtest86パス、およびRowHammerテストを一晩生存 ○ GPU: GeForce GTX 1060 ● ソフトウェア(OSはUbunru16.04) ○ kernel: 4.8.0-5[468]-generic, その時々の最新upstream kernel ○ gcc: gcc (Ubuntu 5.4.0-6ubuntu1~16.04.4) 5.4.0 20160609 5

Slide 6

Slide 6 text

切り分け: gcc or not ● 無限ビルドスクリプトを流したら10回に1回程度失敗 ○ 失敗する箇所は毎回異なる ● 少なくとも問題はgccとその依存ライブラリではありえない ○ gccは入力(ソースコード)が同じなら出力も同じ ○ シングルスレッド、非シグナルドリブン => 何らかの競合でもなさそう 6

Slide 7

Slide 7 text

容疑者 7 gccやgccが依存するライブラリ Linux kernel ハードウェア 可能性 高 可能性 低

Slide 8

Slide 8 text

教えてGoogle ● Gentoo Forumで同じ/非常に似てる事象が話題に ○ Linux kernel以外のビルドでも再現 : LibreOffice, mesa… ○ 多種多様なHW/SW構成で発生 ○ Ryzenでのみ起きる 8

Slide 9

Slide 9 text

Gentoo Forumに参戦 9 ● Ubuntuでも起きるよ ● distro依存じゃないよ ● gcc関係ないよ ● この方法で確実に再現できたよ

Slide 10

Slide 10 text

記録抹殺刑 10 フォーラムへの発言履歴が抹消される Ubuntuの話すんな

Slide 11

Slide 11 text

AMDに報告 ● AMDサポートフォーラムの既存スレッドを利用 ○ 公式の方法 ○ たくさんの人が困っていることを示して重要度を上げてもらいたい ○ みんなで情報共有したほうが問題を切り分けしやすい ● Gentooフォーラムとtwitter(後述)を含めると数十人から再現報告あり 11

Slide 12

Slide 12 text

twitter上での不穏な動き ● 同志を見つけたい&面白ネタなのでtwitterで逐次進捗をつぶやいてた 12

Slide 13

Slide 13 text

twitter上での不穏な動き ● 同志を見つけたい&面白ネタなのでtwitterで逐次進捗をつぶやいてた ● 「RyzenはgccでSEGVが起こせるらしい」「やった、出た!」「出ない…」 13

Slide 14

Slide 14 text

twitter上での不穏な動き ● 同志を見つけたい&面白ネタなのでtwitterで逐次進捗をつぶやいてた ● 「RyzenはgccでSEGVが起こせるらしい」「やった、出た!」「出ない…」 ● 「Ryzen買うのはガチャ」「起きたら当たり石」「修正品は詫び石」 14

Slide 15

Slide 15 text

● ルール ○ SEGV再現試験を実施 ○ ひたすら結果と調査状況を twitterにつぶやく ○ ハッシュタグは#Ryzen_SEGV_Battle 15

Slide 16

Slide 16 text

知人からの激励 16 ど R う Y で Z す E か N !? ん 直 じ ん ゃ な ね い !? な 半 直 る 分 っ ん く て じ ら も ゃ い 性 ね に 能 !? こ 俺 と 何 し か た 悪 !? い

Slide 17

Slide 17 text

Youtubeで生配信される 17

Slide 18

Slide 18 text

解析: linuxカーネル or not? ● WSL(bash on Windows)において、同じ手順で問題発生 ○ fork()の失敗という形で顕在化 ● NetBSDでも同じ手順でのSEGV発生事例あり ● 3つのOS全てに同じ/類似のバグがある確率 <<< ハード問題の確率 18 make[3]: fork: Invalid argument make[2]: *** [arch/x86/realmode/rm/realmode.bin] Error 2 make[1]: *** [arch/x86/realmode] Error 2 make[1]: *** Waiting for unfinished jobs.... make: *** [arch/x86] Error 2 make: *** Waiting for unfinished jobs....

Slide 19

Slide 19 text

容疑者 19 gccやgccが依存するライブラリ Linux kernel ハードウェア 可能性 高 可能性 低

Slide 20

Slide 20 text

ここから先、自分ができること ● ソフト屋の観点から事象の詳細調査&問題の所在を絞り込む ● 根本原因はモノを作ったAMDにしかわからない ● 原因不明のままSW/HW設定を変えたら直った…ではまずい ○ 本当に直っている根拠が無い ○ HW設定変更による別のトラブル (パーツが壊れる等)は避けたい ● ベンダが根本原因を特定した上での公式解決策が必要 20

Slide 21

Slide 21 text

● SEGVと言っても原因はいろいろ ● ftraceを使ってシグナルイベントをトレース 具体的にどんなSEGV? 21 TRACEDIR=/sys/kernel/debug/tracing/ echo 1 > ${TRACEDIR}/events/signal/signal_generate/enable echo '!stacktrace' > ${TRACEDIR}/events/signal/signal_generate/trigger echo 'stacktrace if sig == 11' > ${TRACEDIR}/events/signal/signal_generate/trigger echo 1 > ${TRACEDIR}/tracing_on echo > ${TRACEDIR}/trace

Slide 22

Slide 22 text

トレース結果 code=128 comm=cc1 pid=19539 grp=0 res=0 <...>-19539 [014] d... 3257.455416: => send_signal => force_sig_info => do_general_protection => general_protection 22 ● General Protection Fault(GPF)で死亡 ○ アクセス許可が無いメモリに触る ○ ユーザプログラムから特権命令を実行 ○ その他色々

Slide 23

Slide 23 text

もうちょっと深堀り ● GPFの詳細をログに出すカーネルパッチを作成 23 --- a/arch/x86/kernel/traps.c +++ b/arch/x86/kernel/traps.c @@ -514,10 +514,9 @@ do_general_protection(struct pt_regs *regs, long error_code) tsk->thread.error_code = error_code; tsk->thread.trap_nr = X86_TRAP_GP; - if (show_unhandled_signals && unhandled_signal(tsk, SIGSEGV) && - printk_ratelimit()) { - pr_info("%s[%d] general protection ip:%lx sp:%lx error:%lx", - tsk->comm, task_pid_nr(tsk), + if (show_unhandled_signals) { + pr_err("CPU%u: %s[%d] general protection ip:%lx sp:%lx error:%lx", + tsk->cpu, tsk->comm, task_pid_nr(tsk), regs->ip, regs->sp, error_code);

Slide 24

Slide 24 text

カスタムカーネルのログ ● エラーコード0: セグメント違反ならセレクタのindexになるので、それ以外 24 traps: CPU2: cc1[15404] general protection ip:e4f4f4 sp:7ffe1aefc4a0 error:0 in cc1[400000+13d4000] traps: CPU15: cc1[31616] general protection ip:d0d253 sp:7fffd764db60 error:0 in cc1[400000+13d4000] traps: CPU3: cc1[14060] general protection ip:1131185 sp:7ffc6b6f71b0 error:0 in cc1[400000+13d4000] traps: CPU8: cc1[18405] general protection ip:d0d253 sp:7ffc7ac2e930 error:0 in cc1[400000+13d4000] traps: CPU0: cc1[31556] general protection ip:fc0d7c sp:7ffede8d0630 error:0 in cc1[400000+13d4000] ...

Slide 25

Slide 25 text

● メモリアクセスしていないのにSEGVが起きていることがある SEGVに実行していた命令 * d0d0c9: 45 01 ee add %r13d,%r14d * d0d253: e9 e3 fe ff ff jmpq d0d13b <_Z19cselib_process_insnP8rtx_insn@@Base+0x38b> *1131150: 41 c6 44 24 04 35 movb $0x35,0x4(%r12) *113117d: 41 83 ed 71 sub $0x71,%r13d *1131185: 66 43 f7 84 12 60 2e testw $0x204,0x1622e60(%r10,%r10,1) *1131190: 0f 84 1a 05 00 00 je 11316b0 <_cpp_lex_token@@Base+0x6a0> *11311ad: 45 8d 6c 32 8f lea -0x71(%r10,%rsi,1),%r13d * fe41ba: 76 24 jbe fe41e0 <_Z16get_nonzero_bitsPK9tree_node@@Base+0x40> * e4f4f4: 48 85 c0 test %rax,%rax * e4f4f4: 48 85 c0 test %rax,%rax * fc0d7c: 48 85 c0 test %rax,%rax ... 25

Slide 26

Slide 26 text

新キャラ登場 ● スーパーハカーHideki Eirakuさん ● Ryzen SEGV Battle開幕「後」にRyzenを購入 ● 純粋に「何が起きているか」に興味を持ったらしい 26

Slide 27

Slide 27 text

えいらくさんの解析手法 ● BitVisor(ハイパーバイザの一つ)を使用 ● SEGV発生時にLinux VMを停止させて、その時の状態を調査 ● SEGV発生直前のbranchに関する情報をLastBranchRecordから採取 ○ LastBranchFromIP: 最後のbranchは、どの命令から飛んだか ○ LastBranchToIP: 最後のbranchは、どの命令に飛んだか 27 ハードウェア BitVisor linux SEGV発生 トラップ

Slide 28

Slide 28 text

IPとLast Branch Recordの情報 ● SEGV時rip(0x0101356e) ● LastBranchFromIP(0xc67aee), LastBranchToIP(0x01013560) 28 => 0x101356e <_Z22private_is_attribute_pPKcmPK9tree_node+14>: jb 0x1013588 <_Z22private_is_attribute_pPKcmPK9tree_node+40> c67aee: e8 6d ba 3a 00 callq 1013560 メモリアクセス無し

Slide 29

Slide 29 text

スタックの確認 ● SEGV時rip(0x0101356e) ● LastBranchFromIP(0xc67aee), LastBranchToIP(0x01013560) ● rsp(0x7ffe731e3668)の中身 29 => 0x101356e <_Z22private_is_attribute_pPKcmPK9tree_node+14>: jb 0x1013588 <_Z22private_is_attribute_pPKcmPK9tree_node+40> c67aee: e8 6d ba 3a 00 callq 1013560 0x7ffe731e3668: 0x0000000000c67af3 0x000000fb00000010 ● 恐らく現在のスタックフレームから の戻りアドレス ● LastBranchFromIPの次の命令

Slide 30

Slide 30 text

SEGV時の各種レジスタの確認 ● LastBranchToIPからの実行の流れ 30 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 ● rspは戻りアドレスを指している ● 辻褄が合わない RIP LastBranchToIP 以下5命令を実行したはず

Slide 31

Slide 31 text

仮説 ● call時にLastBranchToIPから0x40バイト低位の命令に飛んだ? ○ 事前調査で「ripが0x40バイト手前にあれば辻褄が合いそう」という例が複数あったらしい 31 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 rip - 0x40 LastBranchToIP - 0x40 以下5命令を実行した?

Slide 32

Slide 32 text

仮説の検証: 1個目の命令 ● (0x10 + rdi)とrdxが等しい => 辻褄が合う 32 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 (gdb) x/xg 0x10+$rdi 0x15b7afd: 0x000a656c63796320 (gdb) p/x $rdx $5 = 0xa656c63796320 この間rdi,rdxは変更なし

Slide 33

Slide 33 text

仮説の検証: 2-4個目の命令 ● 0x101352でジャンプしていない & eaxは0x1 => 辻津が合う 33 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 (gdb) p/x $rax $6 = 0x1 rdx = 0xa656c63796320 != 0

Slide 34

Slide 34 text

仮説の検証: 5個目の(実際に動いてた?)命令 ● 0x10 + rdx(= 0xa656c63796320)は現在のx86_64 CPUの仮想アドレス空間 (48bit)を超えているのでGPF発生 => 辻褄が合う 34 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

Slide 35

Slide 35 text

仮説の検証: BitVisorによるデータ修正&実行再開 1. 1つ目の命令((LastBranchToIP - 40) = 0x1013520)から死亡時までに変更された レジスタ(%rdx, %eax, 各種フラグレジスタ)を復元 2. 本来あるべきripからlinux VM実行を再開 3. 継続動作に成功 => 辻褄が合う 続きはえいらくさんのブログで… 35 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 巻き戻し

Slide 36

Slide 36 text

0x40バイトずれについての考察 ● これですべて説明つく? ○ 説明つくものもあれば、まだ不明なものもある ○ ずれてからしばらく実行継続すると、最終的に何が起きても不思議ではない ■ 途中でcall/jmpするかも ■ 0x40バイト完走後はどこを実行するか不明 ● SEGV以外の事象は起きないの? ○ futex()待ちでwaitすることもある ○ VM起動中に負荷を流すとシステムが超スローダウン ○ 現時点でSIGILLやオブジェクトファイルの破壊は未確認 ● 0x40バイトはキャッシュラインのサイズ => キャッシュに何か問題が? ○ uop cache切っても問題が出る人がいるので uop cacheだけでは説明つかなさそう 36

Slide 37

Slide 37 text

結局どのハードが原因? ● 有志のユーザから出た対処案は、どれも一部の人にしか効果なし ○ CPU以外のパーツ変更 ○ メモリ周波数、枚数の変更、 ECCメモリの使用 ○ CPU(コア、アンコア)の電圧変更、uop cache無効化、ハイパースレッド無効化 ○ Kernel Address Space Location Randomization(KASLR)無効化 ● 全員に共通しているハードはCPUのみ ● 仮説: 様々な要素が発生確率に影響する何らかの根本原因がRyzenに存在? 37

Slide 38

Slide 38 text

サポートフォーラムでのAMDの反応 ● ユーザによる報告、解析結果を全無視、ダンマリ => 炎上 38 AMD

Slide 39

Slide 39 text

サポート担当者を動かす方法の一例 1. 問題があることを認識してもらう => done 2. 再現させる => done 3. インパクトの大きさを訴える => done 4. 具体的に何が悪いのかを明らかにする => done 5. 偉い人にエスカレーション ○ AMDに知り合いはいない 39

Slide 40

Slide 40 text

AMDのCEOに直訴 40

Slide 41

Slide 41 text

大成功 41 ● 速攻でサポートコミュニティ上に個別 対応開始のアナウンス ● 自分はすぐ交換対応に

Slide 42

Slide 42 text

SEGV廃人へのプレゼント ● 交換手続き中にマシンが使えないとtwitterでぼやいていた ● tamtamさんという方がRyzenを買ってくれた ○ 面識無し ○ Twitter上での過去の絡みも無し 42 デュアルRyzen(1socket)

Slide 43

Slide 43 text

SEGV廃人へのプレゼント ● 交換手続き中にマシンが使えないとtwitterでぼやいていた ● tamtamさんという方がRyzenを買ってくれた ○ 面識無し ○ Twitter上での過去の絡みも無し ● プレゼントされた石でもあっさり再現 ○ 再現頻度は低下(数十分~数時間程度に一回 ) 43 デュアルRyzen(1socket)

Slide 44

Slide 44 text

交換品の再現試験 ● SEGVは起きなくなったが別の2つの問題が発生 ○ 数分~数十分に一回 MCE ○ ○ 数十分~数時間に一回ハング ● 他の人の交換状況: 1名は問題解決。残り4,5人は引き続きSEGV発生 44 [ 627.958024] mce: [Hardware Error]: Machine check events logged [ 627.958027] [Hardware Error]: Corrected error, no action required. [ 627.958034] [Hardware Error]: CPU:13 (17:1:1) MC3_STATUS[-|CE|MiscV|-|-|-|-|SyndV|-]: 0x9820000000000150 [ 627.958037] [Hardware Error]: IPID: 0x000300b000000000, Syndrome: 0x000000002a000503 [ 627.958040] [Hardware Error]: Decode Unit Extended Error Code: 0 [ 627.958041] [Hardware Error]: Decode Unit Error: uop cache tag parity error. [ 627.958044] [Hardware Error]: cache level: RESV, tx: INSN, mem-tx: IRD

Slide 45

Slide 45 text

サポートフォーラムでのAMDの反応 ● またダンマリ。炎上 45 AMD

Slide 46

Slide 46 text

転機 ● RedditにおいてEPYCでも問題が起きると噂に ○ gccとは異なる独自再現プログラムを使用 46

Slide 47

Slide 47 text

転機 ● RedditにおいてEPYCでも問題が起きると噂に ○ gccとは異なる独自再現プログラムを使用 ● 再現プログラムのバグと判明 => AMDもRedditに火消しをしにきた 47

Slide 48

Slide 48 text

転機 ● RedditにおいてEPYCでも問題が起きると噂に ○ gccとは異なる独自再現プログラムを使用 ● 再現プログラムのバグと判明 => AMDもRedditに火消しをしにきた ● その直後、AMDがPhoronix(技術系ニュースサイト)に対してコメント ○ 初期のRyzenにはgcc負荷によるSEGV問題が存在する(原因についてはほぼ言及無し ) ○ EPYC、Threadripperでは起きない(Ryzen Proについては言及無し ) ○ 問題が起きるユーザには個別対応する (事実上SEGV問題テスト済みの石への交換 ) 48

Slide 49

Slide 49 text

二回目のRMA 49 トライRyzen(1socket)

Slide 50

Slide 50 text

ついに24時間の耐久テストをパス ● 約4か月がかりで、ようやく終戦 50

Slide 51

Slide 51 text

その後 ● 市場に出回ってる古いRyzenは回収されていない模様 ● 現時点で確実にSEGVしない石を手に入れる方法 1. 買う 2. SEGVするかどうか確認 3. 当たり石ならRMA ● AMDはまたダンマリ。サポートフォーラムは絶賛炎上中 51

Slide 52

Slide 52 text

サポートフォーラムのSEGVスレへの投稿数 52 6/12 直訴& 個別対応開始 8/7 AMDが問題を認める

Slide 53

Slide 53 text

めでたしめでたし 53 AMD