Ryzen SEGV Battle

The result of the analysis of so called SEGV (or segfault) problem in Ryzen processor

Transcript

1. Ryzen SEGV Battle Sep 23 2017 Satoru Takeuchi satoru.takeuchi@gmail.com twitter: satoru_takeuchi 1
2. はじめに • 最新のRyzen 1800X(8core 16 thread)搭載のPCを新調 • linuxカーネル(defconfig)のビルド速度は1分(先代マシンの5倍高速) 2
3. 終わりの始まり • 何度かカーネルビルドしたら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 <file:///usr/share/doc/gcc-5/README.Bugs> for instructions.
4. 容疑者 4 gccやgccが依存するライブラリ Linux kernel ハードウェア 可能性 高 可能性 低
5. 検証環境 • ハードウェア ◦ 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
6. 切り分け: gcc or not • 無限ビルドスクリプトを流したら10回に1回程度失敗 ◦ 失敗する箇所は毎回異なる • 少なくとも問題はgccとその依存ライブラリではありえない ◦ gccは入力(ソースコード)が同じなら出力も同じ ◦ シングルスレッド、非シグナルドリブン => 何らかの競合でもなさそう 6
7. 容疑者 7 gccやgccが依存するライブラリ Linux kernel ハードウェア 可能性 高 可能性 低
8. 教えてGoogle • Gentoo Forumで同じ/非常に似てる事象が話題に ◦ Linux kernel以外のビルドでも再現 : LibreOffice, mesa… ◦ 多種多様なHW/SW構成で発生 ◦ Ryzenでのみ起きる 8
9. Gentoo Forumに参戦 9 • Ubuntuでも起きるよ • distro依存じゃないよ • gcc関係ないよ • この方法で確実に再現できたよ
10. 記録抹殺刑 10 フォーラムへの発言履歴が抹消される Ubuntuの話すんな
11. AMDに報告 • AMDサポートフォーラムの既存スレッドを利用 ◦ 公式の方法 ◦ たくさんの人が困っていることを示して重要度を上げてもらいたい ◦ みんなで情報共有したほうが問題を切り分けしやすい • Gentooフォーラムとtwitter(後述)を含めると数十人から再現報告あり 11
12. twitter上での不穏な動き • 同志を見つけたい&面白ネタなのでtwitterで逐次進捗をつぶやいてた 12
13. twitter上での不穏な動き • 同志を見つけたい&面白ネタなのでtwitterで逐次進捗をつぶやいてた • 「RyzenはgccでSEGVが起こせるらしい」「やった、出た!」「出ない…」 13
14. twitter上での不穏な動き • 同志を見つけたい&面白ネタなのでtwitterで逐次進捗をつぶやいてた • 「RyzenはgccでSEGVが起こせるらしい」「やった、出た!」「出ない…」 • 「Ryzen買うのはガチャ」「起きたら当たり石」「修正品は詫び石」 14
15. • ルール ◦ SEGV再現試験を実施 ◦ ひたすら結果と調査状況を twitterにつぶやく ◦ ハッシュタグは#Ryzen_SEGV_Battle 15
16. 知人からの激励 16 ど R う Y で Z す E か N !? ん 直 じ ん ゃ な ね い !? な 半 直 る 分 っ ん く て じ ら も ゃ い 性 ね に 能 !? こ 俺 と 何 し か た 悪 !? い
17. Youtubeで生配信される 17
18. 解析: 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....
19. 容疑者 19 gccやgccが依存するライブラリ Linux kernel ハードウェア 可能性 高 可能性 低
20. ここから先、自分ができること • ソフト屋の観点から事象の詳細調査&問題の所在を絞り込む • 根本原因はモノを作ったAMDにしかわからない • 原因不明のままSW/HW設定を変えたら直った…ではまずい ◦ 本当に直っている根拠が無い ◦ HW設定変更による別のトラブル (パーツが壊れる等)は避けたい • ベンダが根本原因を特定した上での公式解決策が必要 20
21. • 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
22. トレース結果 code=128 comm=cc1 pid=19539 grp=0 res=0 <...>-19539 [014] d... 3257.455416: <stack trace> => send_signal => force_sig_info => do_general_protection => general_protection 22 • General Protection Fault(GPF)で死亡 ◦ アクセス許可が無いメモリに触る ◦ ユーザプログラムから特権命令を実行 ◦ その他色々
23. もうちょっと深堀り • 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);
24. カスタムカーネルのログ • エラーコード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] ...
25. • メモリアクセスしていないのに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
26. 新キャラ登場 • スーパーハカーHideki Eirakuさん • Ryzen SEGV Battle開幕「後」にRyzenを購入 • 純粋に「何が起きているか」に興味を持ったらしい 26
27. えいらくさんの解析手法 • BitVisor(ハイパーバイザの一つ)を使用 • SEGV発生時にLinux VMを停止させて、その時の状態を調査 • SEGV発生直前のbranchに関する情報をLastBranchRecordから採取 ◦ LastBranchFromIP: 最後のbranchは、どの命令から飛んだか ◦ LastBranchToIP: 最後のbranchは、どの命令に飛んだか 27 ハードウェア BitVisor linux SEGV発生 トラップ
28. 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 メモリアクセス無し
29. スタックの確認 • 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の次の命令
30. 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命令を実行したはず
31. 仮説 • 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命令を実行した?
32. 仮説の検証: 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は変更なし
33. 仮説の検証: 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
34. 仮説の検証: 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
35. 仮説の検証: 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 巻き戻し
36. 0x40バイトずれについての考察 • これですべて説明つく? ◦ 説明つくものもあれば、まだ不明なものもある ◦ ずれてからしばらく実行継続すると、最終的に何が起きても不思議ではない ▪ 途中でcall/jmpするかも ▪ 0x40バイト完走後はどこを実行するか不明 • SEGV以外の事象は起きないの? ◦ futex()待ちでwaitすることもある ◦ VM起動中に負荷を流すとシステムが超スローダウン ◦ 現時点でSIGILLやオブジェクトファイルの破壊は未確認 • 0x40バイトはキャッシュラインのサイズ => キャッシュに何か問題が? ◦ uop cache切っても問題が出る人がいるので uop cacheだけでは説明つかなさそう 36
37. 結局どのハードが原因? • 有志のユーザから出た対処案は、どれも一部の人にしか効果なし ◦ CPU以外のパーツ変更 ◦ メモリ周波数、枚数の変更、 ECCメモリの使用 ◦ CPU(コア、アンコア)の電圧変更、uop cache無効化、ハイパースレッド無効化 ◦ Kernel Address Space Location Randomization(KASLR)無効化 • 全員に共通しているハードはCPUのみ • 仮説: 様々な要素が発生確率に影響する何らかの根本原因がRyzenに存在? 37
38. サポートフォーラムでのAMDの反応 • ユーザによる報告、解析結果を全無視、ダンマリ => 炎上 38 AMD
39. サポート担当者を動かす方法の一例 1. 問題があることを認識してもらう => done 2. 再現させる => done 3. インパクトの大きさを訴える => done 4. 具体的に何が悪いのかを明らかにする => done 5. 偉い人にエスカレーション ◦ AMDに知り合いはいない 39
40. AMDのCEOに直訴 40
41. 大成功 41 • 速攻でサポートコミュニティ上に個別 対応開始のアナウンス • 自分はすぐ交換対応に
42. SEGV廃人へのプレゼント • 交換手続き中にマシンが使えないとtwitterでぼやいていた • tamtamさんという方がRyzenを買ってくれた ◦ 面識無し ◦ Twitter上での過去の絡みも無し 42 デュアルRyzen(1socket)
43. SEGV廃人へのプレゼント • 交換手続き中にマシンが使えないとtwitterでぼやいていた • tamtamさんという方がRyzenを買ってくれた ◦ 面識無し ◦ Twitter上での過去の絡みも無し • プレゼントされた石でもあっさり再現 ◦ 再現頻度は低下(数十分～数時間程度に一回 ) 43 デュアルRyzen(1socket)
44. 交換品の再現試験 • 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
45. サポートフォーラムでのAMDの反応 • またダンマリ。炎上 45 AMD
46. 転機 • RedditにおいてEPYCでも問題が起きると噂に ◦ gccとは異なる独自再現プログラムを使用 46
47. 転機 • RedditにおいてEPYCでも問題が起きると噂に ◦ gccとは異なる独自再現プログラムを使用 • 再現プログラムのバグと判明 => AMDもRedditに火消しをしにきた 47
48. 転機 • RedditにおいてEPYCでも問題が起きると噂に ◦ gccとは異なる独自再現プログラムを使用 • 再現プログラムのバグと判明 => AMDもRedditに火消しをしにきた • その直後、AMDがPhoronix(技術系ニュースサイト)に対してコメント ◦ 初期のRyzenにはgcc負荷によるSEGV問題が存在する(原因についてはほぼ言及無し ) ◦ EPYC、Threadripperでは起きない(Ryzen Proについては言及無し ) ◦ 問題が起きるユーザには個別対応する (事実上SEGV問題テスト済みの石への交換 ) 48
49. 二回目のRMA 49 トライRyzen(1socket)
50. ついに24時間の耐久テストをパス • 約4か月がかりで、ようやく終戦 50
51. その後 • 市場に出回ってる古いRyzenは回収されていない模様 • 現時点で確実にSEGVしない石を手に入れる方法 1. 買う 2. SEGVするかどうか確認 3. 当たり石ならRMA • AMDはまたダンマリ。サポートフォーラムは絶賛炎上中 51
52. サポートフォーラムのSEGVスレへの投稿数 52 6/12 直訴& 個別対応開始 8/7 AMDが問題を認める
53. めでたしめでたし 53 AMD