コーディング練習: 人の書いたプログラムを自分の方法で書き直す
web上で、とある凄腕エンジニアのかたが実装した簡単なプログラミング言語の実装と、その様子を紹介したビデオを見つけました。
思うところあって、プログラムの仕様をできるだけ変えないまま、自分なりに書き直す練習をしたかったので、ちょうどいい小さな規模のこのプログラムで実践してみました。
仕様を変えないまま…とは言っても仕様が文書なりで明確化されていたわけではないので、ソースから著者の意図を推測しただけです。一から書き直すという方法もありますが、今回は既存のソースを改編するという方法をとりました。
変更点は次の通り。
- 仕様っぽいもの(すごく柔らかい、お金を取るプロダクトの仕様書として出したら殴られるレベルのもの。ここではこれでいいんです)をソース冒頭に書いた
- 関数名、変数名(とくにグローバル変数)は何をしているものなのかをわかりやすくした
- エラーチェックの追加: 引数の数、バッファオーバーランなど
- print機能(P()関数)による出力と、トップレベルの文を評価した際の出力を区別できるようにした
- 雑多なバグ修正
もう少しこだわると、コードへのポインタはグローバル変数ではなく関数引数にしたかったんですが、無用にややこしくするだけになる恐れがあったので、やめました。
可読性においては初級者には見やすくなっていると思います。その一方で、上級者にとっては冗長に見えるかと思います。それらはオリジナルソースの作者と私の好みの違い、および、ソースをどれだけ気合を入れて書いたかの違いでしょう。「俺だったらここはこうするね」という意見も多々あろうかと思います。色々な人が同じことをした場合のソースを並べて見てみたいものです。
この試みはけっこう面白かったので、他のソースでもやってみようかと思います。オレオレプログラムを書く場合とは異なる脳の部位を使っている気がします。
ノートPCに仕込まれていたキーロガーを削除した
三日前にこんなニュースが飛び込んできました。
で、私が最近買ったPCはHP製品です。
satoru-takeuchi.hatenablog.com
該当PCの一覧にもありました。あーあ。
https://www.modzero.ch/advisories/MZ-17-01-Conexant-Keylogger.txt
こんなのを仕込まれていてはたまらないので、問題となる実行ファイルを削除しました。ログファイル(c:/Users/Public/MicTray.log)にパスワードを含む打鍵履歴が山盛り記録されていて肝を冷やしたかったのですが、残念ながら当該ファイルは空であり、かつ、変更日時はOSインストール時とおもわしきものでした。私のPCにインストールされているバージョンのドライバではロギングしていないのか、あるいはログファイルはスーパーハカーの手によって変更履歴が改竄されているのかは知らないです。
ただこの話は、迷惑かついい気分がしないのは確かなんですが、
- ログを".log"というわかりやすい拡張子のファイルに保存している
- ドライバ自身からはネットワーク転送していないらしい
- 全ユーザにファイルが読める
という隠す気ゼロのしょっぱい作りなあたり、わざとでなく本当に「やっちゃった」だけなのでは?というのは感じます(後付けで何を言っても真意は作者にしかわかりませんが…)。
5/14に落ちてきたWindows Update “Conexant - MEDIA - 5/14/2017 12:00:00 AM - 9.0.134.1"によって、問題のログファイルは消され、かつそれを作っていると思わしき実行ファイルは更新されていたので、これが修正なのでしょう。こういうのは黙って直すだけではなく、HPからなんらかのアナウンスが欲しいところです。がっかり。
Ryzenにまつわる2つの問題
NOTE1: 2017/8/12に2つ目の問題について更新しました。ついに両方の問題が解決しました。
NOTE2: 2つ目の問題についてはすべての経緯をまとめた書籍があります。
4月にRyzenを積んだデスクトップマシンを買いました。その上で日課であるカーネルビルド&テストをした*1ことをきっかけに、2つの問題が発生しました。先代のCore i5を積んだマシンでは起きなかった現象です。
このエントリは自分用のメモがてら、新しいことがわかれば随時更新していきます。後者については9月に開催されたkernelvm北陸にて、本ブログには書かれていない解析の詳細などについて発表してきました。
www.slideshare.net
環境
ハードウェア
- CPU: Ryzen 1800X
- Motherboard: ASUS PRIME X370-PRO
- BIOS: 0604(AGESA 1.0.0.4a)。設定はSVM以外デフォルト
- DIMM: Kingston KVR24N17S8/8 * 4 (8 * 4 = 32GB)。QVLには載っていないがAMDからはOKをもらっている構成
- GPU: GeForce GTX 1060
ソフトウェア
問題1: VM上でAVX2命令を実行した時に不正な命令を実行したとみなされる
要約
[原因]
[対策]
[回避方法]
詳細
ブート時のカーネルのログはこんなかんじ。
... [ 0.227720] raid6: sse2x1 gen() 7985 MB/s [ 0.295709] raid6: sse2x1 xor() 8181 MB/s [ 0.363706] raid6: sse2x2 gen() 17531 MB/s [ 0.431699] raid6: sse2x2 xor() 11098 MB/s [ 0.499693] raid6: sse2x4 gen() 18509 MB/s [ 0.567688] raid6: sse2x4 xor() 10177 MB/s [ 0.571692] invalid opcode: 0000 [#1] SMP [ 0.572312] Modules linked in: [ 0.572822] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.11.0-rc8-ktest #1 [ 0.573734] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Ubuntu-1.8.2-1ubuntu1 04/01/2014 [ 0.575040] task: ffff8f791e1c0000 task.stack: ffff9c72c00d0000 [ 0.575865] RIP: 0010:raid6_avx21_gen_syndrome+0x3d/0x120 [ 0.576634] RSP: 0018:ffff9c72c00d3d70 EFLAGS: 00010246 [ 0.577376] RAX: 0000000000000000 RBX: ffff9c72c00d3dc0 RCX: 00000000fffedb97 [ 0.578327] RDX: 0000000000000000 RSI: 0000000000001000 RDI: 0000000000000012 [ 0.579283] RBP: ffff9c72c00d3da0 R08: 0000000000000000 R09: 00000000000000cd [ 0.580243] R10: 00000000fffedb86 R11: ffffffffa617008d R12: 0000000000001000 [ 0.581211] R13: ffff8f791e39e000 R14: ffff8f791e39f000 R15: 0000000000000012 [ 0.582163] FS: 0000000000000000(0000) GS:ffff8f791fc00000(0000) knlGS:0000000000000000 [ 0.583324] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 0.584128] CR2: 0000000000000000 CR3: 000000001be09000 CR4: 00000000003006f0 [ 0.585078] Call Trace: [ 0.594952] raid6_select_algo+0x116/0x30b [ 0.595592] ? libcrc32c_mod_init+0x2b/0x2b [ 0.596240] do_one_initcall+0x53/0x1a0 [ 0.596843] ? parse_args+0x2cf/0x490 [ 0.597421] kernel_init_freeable+0x182/0x21c [ 0.598077] ? rest_init+0x80/0x80 [ 0.598626] kernel_init+0xe/0x100 [ 0.599175] ret_from_fork+0x2c/0x40 [ 0.599741] Code: 55 41 54 53 48 89 d3 48 8d 14 c5 00 00 00 00 41 89 ff 49 89 f4 48 83 ec 08 4c 8b 2c c3 4c 8b 74 13 08 48 89 55 d0 e8 53 ed a9 ff <c5> fd 6f 05 2b 2d 4e 00 c5 e5 ef db 4d 85 e4 48 8b 55 d0 0f 84 [ 0.602215] RIP: raid6_avx21_gen_syndrome+0x3d/0x120 RSP: ffff9c72c00d3d70 [ 0.603154] ---[ end trace 17ee01f86b8fc548 ]--- [ 0.603850] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b [ 0.603850] [ 0.605276] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b ...
AVX2命令の実行中に不正な命令を発行したとしてパニックしています。RyzenではAVX2命令が使えるはずだし、AMDのマニュアルを見ると仮想化環境では使えないとか書いてないように見えるし(隅から隅まで読んだわけではないので間違ってるかも)、なんかおかしい。次のようなダーティハックでとりあえずブートできるようにはなった。as-instrが何をするものなのかは知りません。
]diff --git a/arch/x86/Makefile b/arch/x86/Makefile index 2d44933..b589097 100644 --- a/arch/x86/Makefile +++ b/arch/x86/Makefile @@ -162,7 +162,7 @@ asinstr := $(call as-instr,fxsaveq (%rax),-DCONFIG_AS_FXSAVEQ=1) asinstr += $(call as-instr,pshufb %xmm0$(comma)%xmm0,-DCONFIG_AS_SSSE3=1) asinstr += $(call as-instr,crc32l %eax$(comma)%eax,-DCONFIG_AS_CRC32=1) avx_instr := $(call as-instr,vxorps %ymm0$(comma)%ymm1$(comma)%ymm2,-DCONFIG_AS_AVX=1) -avx2_instr :=$(call as-instr,vpbroadcastb %xmm0$(comma)%ymm1,-DCONFIG_AS_AVX2=1) +#avx2_instr :=$(call as-instr,vpbroadcastb %xmm0$(comma)%ymm1,-DCONFIG_AS_AVX2=1) avx512_instr :=$(call as-instr,vpmovm2b %k1$(comma)%zmm5,-DCONFIG_AS_AVX512=1) sha1_ni_instr :=$(call as-instr,sha1msg1 %xmm0$(comma)%xmm1,-DCONFIG_AS_SHA1_NI=1) sha256_ni_instr :=$(call as-instr,sha256msg1 %xmm0$(comma)%xmm1,-DCONFIG_AS_SHA256_NI=1)
とりえあずは問題を整理してバグ報告しました。
LKML: Satoru Takeuchi: [BUG] x86: failed to boot a kernel on a Ryzen machine
幸いにもBorislav Petkovさん(linuxカーネルのいろんなコンポのメンテナ)からレスをいただき、彼のの環境で再現もできました。かつ、AMDのRyzen Engineering Teamにも転送されたようです。
その後Masami Hiramatsuさん(kprobesのメンテナ)から、VMに見えているCPUのモデルと機能フラグの組み合わせの問題では、という指摘を受けました。
自分の環境ではlibvirtを使ってVMを管理しています。CPUのモデルはhostと同じもの(host-model)になるよう設定しているのですが、今のlibvirtではそれが実際には古いOpteron_G3に設定されます。これを、CPUのモデルをOpteron_G5にして、かつ、Ryzenがサポートしない機能(fma4, tbm, およびXOP)のフラグを落としたところ、無事上記カーネルで起動成功しました。
その後さらにPaolo Bonziniさん(KVMのメンテナかつqemu開発者)に、新しいCPUではこういうことがよくあること、およびmodeを"host-passthrough"にするように言われ、その通りにするとパニックしなくなりました。これでqemuのCPU modelにRyzen(あるいはZen)を追加してもらえれば完了なはずです。
問題2: gccによるビルドがランダムに失敗して、SEGVが発生する
[原因]
- Ryzenの初期の頃の生産分にあった複雑な障害。詳細は不明かつ非公開。今後公開されるかは不明
- 何らかの理由によりcall(サブルーチン呼び出し)命令発行時に本来のものより0x40低位アドレスの命令を実行してしまう。0x40はキャッシュライン長に一致するので、命令キャッシュの扱いに何等かの不具合があるのかもしれない
[影響]
- 現在知られているのはSEGV(発生するとプログラムが異常終了するので検知しやすい)によるプログラムの異常終了。誤ってどのような命令を実行するかによって、SIGILLやデータ破壊が発生する可能性もある。
[発生契機]
- linux, あるいはWindows Subsystems for Linux(WSL, 後述)上でgccを使った場合(コンパイルするソースは何でもよい)。linuxカーネルなど、大規模なプロジェクトのビルドにおいて主に事例が報告されている。これはビルド時間が長いので発生確率も高いためだと考えられる
- 並列ビルドしなくても単一コア(or スレッド)上のコンパイルで発生する
- 現在わかっている範囲ではgcc on linuxに限らず、どんなOS上のどんな実行ファイルにおいて発生しても不思議ではない(根本原因が明らかになれば発生環境が限定されるかもしれない)
- LinuxやWindowsにおいて、gcc以外の実行でもこの事例という疑いのある事象がいくつか報告されているが、確証は無い。NetBSDにおいてはほぼ間違いなくこの問題であろうという事象がgccの実行中に発生している
[影響範囲]
- 不明
- 筆者の観測範囲では日本だけでも10名以上、海外含めると20名以上の環境(CPU)で発生している
- 問題が起きる人は長時間ビルドすれば確実に事象が再現できるものの、長時間ビルドしても全く問題が起きていない人もいる(両者の比率は不明)。すべての石に問題があるというわけではなさそう
[修正]
[回避方法]
- 多くの提案(ASLR無効化、uops cacheの無効化、ハイパースレッドの無効化など)があるが、全員に効果があるものは今のところ見つかっていない
事象発生
問題1をクリアした後にカーネルビルド&テストを何度か実行したところ、ビルドが次のように失敗したことがありました。
/home/sat/src/elkdat/linux/block/partition-generic.c: In function 'part_alignment_offset_show': /home/sat/src/elkdat/linux/block/partition-generic.c:103:1: internal compiler error: Segmentation fault } ^ Please submit a full bug report, with preprocessed source if appropriate. See <file:///usr/share/doc/gcc-5/README.Bugs> for instructions. /home/sat/src/elkdat/linux/scripts/Makefile.build:294: recipe for target 'block/partition-generic.o' failed make[2]: *** [block/partition-generic.o] Error 1
その後再度ビルドを実行すると成功しました。その後も何度か同じことが起きたために、何か変だと思って腰を据えて調査してみることにしました。試しにカーネルを10回連続でビルドしたら、7回成功して3回はsegmentation faultで死にました。死んだ場所はそれぞれ全然違うところです。このため、gccに関する問題というよりも、CPUやメモリなどのハード関連の問題に見えました。あるいはハードを扱うカーネルのコードが間違っている可能性もありました。
(補足) 6/7現在、いまだにgccが根強く疑われているので、私が当初から「これはgccの問題でない」と考えていた理由をここに書いておきます。指摘には主に二種類あったので、それぞれについて反論の形で記載します。
- gccがRyzenに対応してないコードなんじゃないの? => 私を含めた、この問題を再現した複数人はdistroが提供するgccを使っています。distro提供のgccは(他のパッケージもですが)、よほど古いものを含めてどんなCPUでも動作するようなコード-でできています。仮にRyzenで動かないコードがあっても、同じ再現試験をすると完走することはなく必ず同じところで失敗するはずです(さらにこれはSEGVとは別の大きなCPU障害です)。仮にRyzenに対応したコードになっていたとしても、それはgccの速度が向上するだけです。
- gccが吐くコードをRyzenのZenアーキテクチャ用にしなきゃいけないんじゃないの。古いバージョンのgccだとそのコード吐けないよ => 実行して問題が起きたプロセスはgccなので、gccがその動作中にどのようなコードを吐こうと問題には関係ありません。あるとしたらZen用ではないコードを吐くためのgccのコードがバグっているというくらいですが、そうなると前述の場合と同様、同じ場所で必ずSEGVで死ぬはずです。gccのバージョンやオプションを変えると問題の再現有無、再現確率が変わった例も報告されていますが、それは、たまたまそれらバイナリの命令列が事象再現確率の高いものであるかそうでないかの違いだけです。こういう事象についてはgccを含むユーザプロセスは事象発生のきっかけにはなれても、発生原因にはなりえません。そうだとすると上記のように説明がつかないからです。
Gentooフォーラムに行ったが…
Gentoo Forumでも類似の報告がありました。
Gentoo Forums :: View topic - Segfaults during compilation on AMD Ryzen.
とりあえずGentooではない自分の環境でも再現したこと、つまり問題はdistro非依存であることを同フォーラムに報告しましたが、Ubuntuの話をしたことが気にくわなかったらしい人に怒られて、投稿が削除されてしまいました。これ以上何を言っても話がこじれるだけだと思ったので、その後Gentoo ForumはROMで情報収集するだけに留めることにしました。
最新カーネル(4.12-rc1。この部分の書いた時点では最新)にアップデートした上で再現テストをすると、問題は依然存在することがわかりました。この他に、linuxカーネル以外のLibreOfficeやmesaなどのビルドにおいても同様の問題が発生していることが報告されています。そのほかに、こうすれば直った/回避できたという情報が錯綜していましたが、私の環境ではどれも効果無しでした。
AMDサポートコミュニティでの議論
何かわかることはないかとAMDのサポートに問題を報告した上で、やりとりを始めました。当初はプライベートなサポートチケットを発行したのですが、応答が極端に鈍くてまともに調査してるか、そもそも問題として認識しているのかどうかもわからないような状況だったので困っていました。再度Web上を調査したところ、問題認識当初は無かった、同じ問題についての報告する次のようなスレッドがサポートコミュニティにできていることがわかりました。
ここで「AMDはこの問題をハンドルしてるのか、および、進捗を教えてほしい。できれば公開で」と言うと、公式から「調査中である。進捗があったらここで報告する」という回答を得ました。どうやら問題そのものが無視/黙殺されている最悪のケースは回避できたようなので安心しました。
その後AMDのサポートと何回かやりとりしましたが、こちらについてもあまり頼りにならなかったです。後述の各種情報を報告しても反応が無いし、効果の無いケースのあるワークアラウンドを出して回答済にしようとしたり、最初から言ってる並列ビルド負荷がトリガーの一つであることを最近やっと気づいたようなリアクションをしたりと、CPUのことを知っているエンジニアではなく初期切り分け窓口レベルで対応している疑いがありました。
問題が大きく扱われるようになる
AMDサポートコミュニティが活発化したり(AMDは黙ったまま)、twitterなどのSNSで発生例がいくつも報告されたり、果てはPhoronixに記事にされたり(下記リンク)と順調に火が大きくなって、実際に被害を受けている人以外にもこの問題の知名度が高まっていきました。
Some Ryzen Linux Users Are Facing Issues With Heavy Compilation Loads - Phoronix
そんな中、Phoronixにおいて、DragonFlyBSDでこの問題についてのパッチを書いたMattさんという人が、この問題はハードバグだろうということと、そのロジックを書いてくれました。
Some Ryzen Linux Users Are Facing Issues With Heavy Compilation Loads - Phoronix Forums
そのロジックをもとにしたワークアラウンドを別の人が書いており、それを試すと私の場合は問題が起きなくなりました。
Some Ryzen Linux Users Are Facing Issues With Heavy Compilation Loads - Phoronix Forums
ワークアラウンドは、セキュリティ対策のために設定するプロセスの実行時アドレスをランダム化*2をする機能を無効化するというものです。特定アドレスへのアクセスがダメというところまではこのロジックで納得できたのですが、Mattさんはこの問題をハイパースレッドにまつわるものとみなしているのに対して、私を含む何人かはハイパースレッドの無効化によってSEGVが解消しなかったというところが矛盾しています。これについては、特定アドレスへのアクセスが事象発生に関係しているものの、実際にはハイパースレッドに閉じた話ではないのではと推測しています。
他にもRedditにおいてuop cacheを無効化することによって問題が発生しなくなるという噂がありました。しかし、uop cacheを無効化しても問題が発生するユーザがいたため、少なくともup cacheだけではこの問題は説明できないことが明らかになっています。
Compiling with Ryzen CPUs on Linux causing random segfaults, possible CPU bug : programming
CPUのerrataである可能性が高いことを実験で確認
私のUbuntu環境で事象が再現する負荷をWindows Subsystem for Linux(WSL。いわゆるBash on Ubuntu on Windowns)上でかけたところ、エラーメッセージこそSEGV云々ではないものの、ランダムにビルドが失敗するという事象は発生しました*3。さらに、とある人から、NetBSDにおいて重いビルド負荷をかけるとSEGVないしカーネルパニックが起きること、および、ASLRを無効化すると、さしあたり問題は回避できているということを聞きました。これによって少なくとも問題はLinux固有ではなくなりましたし、ハード問題である疑いが強くなってきました。Ubuntu(というよりlinux全般), WSL, NetBSDのカーネル全てがそれぞれ非常によく似たバグを抱えている可能性は一応残っていますが、その確率は非常に低いでしょう(AMDサポートフォーラムの"2017/06/07 16:23"における投稿)。
問題がハードだとすると、果たしてどのハードが悪いのかという話になりますが、私はRyzenが犯人である可能性が高いと考えました。ちまたでは「メモリが悪い」「オーバークロックしてるから悪い」などの声が多数ありますが、memtestをパスしてオーバークロックもしていない人の報告が二桁に上ること、および、全体として似たような負荷で同じ事象が発生するという報告があまりにも多すぎるという状況から、これらCPU以外のハードの障害では説明つきづらいと思っています。
ここまでわかるともう一つ別のことが言えます。それは、SEGV発生時のgccと似たような処理が実行されれば、他のプログラムであっても同様の問題が起こりえることが言えます。
カーネルトレース情報の採取
色々調査結果を報告してもAMDから反応が無いので若干空しいものの、さらに調査を進めて、カーネルにトレースを仕込んで情報収集の上、分析しました。それによって、ますますCPUが原因ではなかろうかという疑いが強くなりました。分析の結果わかったことのサマリを次に示します(少しだけx86アーキテクチャの知識が必要です)。
- SEGVの原因は原因不明のGeneral Protection Failure*4。要するにソフト屋からは何が起こってるのか全く不明
- GPF発生時のIP(Instruction Pointer)は複数の狭いアドレス空間に集中している。確証は無いが、アドレス番地そのものよりも、そのアドレス付近の命令パターンによる負荷が事象発生に関与しているのではないかと推測
- GPFが同じCPU上で別プロセスに対して立て続けに起きることがあり、かつ、その時のそれぞれのIPは非常に近い。このため、最初のGPFあるいはそれより前の何らかのイベントを契機に、しばらくの間CPUが不安定な状態になるではと推測
- GPF発生時のIPが指す命令は多種多様。それ自身ではメモリを触らないjmp命令の場合もあるので、ますますGPFが発生する理由が謎
詳細については上述のサポートフォーラムに記載していますので、そちらをごらんください。
よりよい再現プログラムを目指して
これまでの情報をもとにgccのコードを一部抜粋したりして再現プログラムを作成しようとしましたが、うまくいきませんでした。ただし、再現プログラムの作成に関しては希望が持てることが1つ明らかになりました。それはCPUコアを1つにして、かつマルチスレッド無効化しても問題は発生したことです。これによって、別コア(スレッド)との相互作用が無くても単一CPUだけでも問題は発生しうると言えます。これまでは、あるCPUにおいてSEGVが発生した際に、それ以外のCPUの挙動が謎だったために、再現プログラムの作成難易度が相当高いと思っていました。しかし、SEGV発生時のCPUの挙動だけを真似れば理屈上再現プログラムが作れることがわかったので、作成の敷居は下がりました(が、その後実際に作業する前に問題が解決ししたのでうやむやになりました…)。
個別対応を引き出す
その後、AMDに再度調査状況を教えてくれるよう促した結果、次のような回答を得ました。
Checking in from AMD. The vast majority of users using Ryzen for Linux code and development have reported very positive results.
A small number of users have reported some isolated issues and conflicting observations. AMD is working with users individually to understand and resolve these issues.
If you are having a specific issue, please raise a service request on: http://support.amd.com/en-us/contact/email-form.
Use “Ryzen Linux Forum Discussion” as the subject and an AMD support person will contact you.
「ここまで待たせておいてその言い方は無いだろう」と、かなり腹が立ちましたが、とりあえずsubjectに"Ryzen Linux Forum Discussion"を入れてサポートリクエストを発行すると個別対応してくれるとの言質をとりました。感覚的に、ここでこれ以上の議論をしても無駄かなと感じました。
私については上記の通りサポートリクエストを発行しました。既に以前発行したサポートリクエスト、および、コミュニティ上で全ての事情を伝えていたこともあってか、すぐにCPUの交換となりました。ただし、errataを認めたわけではなく(これ自身は現時点では当たり前のこと)、さらなる調査の継続のために、私のCPUが不良品である可能性をつぶすための交換という位置づけでした。とりあえずはここで一息ついて、交換後に再度同じ試験をして問題が発生しないかどうかを確認したいと思います。
交換した石
諸々の手続きなどを含め3週間ほど経過した後にようやく交換品が届きました。早速make -j16によるlinux v4.12(執筆時点での最新版)をテストしてみました。
冒頭に記載した環境からの差分は次の通り。
- kernelは4.8.0-58-genericとv4.12
- BIOSは0805(AGESA 1.0.0.6a)
現在のところの試験結果は次の通りでした。
- ランダムなSEGVは発生しなくなった
- ランダム(早ければ10分程度、遅いと数時間)にシステムがハングアップする。その際ディスプレイ信号が無くなっており、復旧にはリセットが必要
- uop cache tagパリティエラー(ログ曰く、エラーの修正はできている)がランダムに出るようになった。
https://gist.github.com/satoru-takeuchi/0ed5a8736aaaa37e3723b9d142794a28
このMCEの頻度は上記ログにおいては5分に1回程度(妙に周期がそろっているのが気になる)です。ただし、リセットを挟んだ別の試験(試験内容は同じ)においては1分程度で出たり1時間以上かかる場合もあったりと、ばらばらです。このMCEについては頻度は不明なものの、Gentooフォーラムにおいて報告例があります。
Gentoo Forums :: View topic - Segfaults during compilation on AMD Ryzen. Gentoo Forums :: View topic - Segfaults during compilation on AMD Ryzen.
このMCEについては、ログを見ると"Corrected error, no action required"とは書いていますが、これだけ頻繁に出ると、まともな状態とは言えないと判断しました。
AMDが問題を認める
そうこうしているうちに、次のリンクに示すように、ついにAMDがRyzenにある問題によってSEGVが発生していることを認めました。将来どうなるかはわかりませんが、今のところはリコールは避けて、問題に遭遇した人だけへの個別の交換対応をするように見えています。
gcc segmentation faults on Ryzen / Linux | Community
問題の公開に踏み切った理由については次のようなものが考えられますが、ただの私の憶測なので全然違うかもしれません。本当のところはAMDにしかわかりません。
- 個別対応になった後にもRMAで直らない人が続出したなどの理由によって、サポートコミュニティ上でのユーザの不満が爆発寸前だったため、耐えきれなくなった
- 上記不満のせいもあってか、Phoronixで記事にされた(二度目)
- 別サイトのRedditにおいてEPYCでも問題が発生するという話題になり、早々に火消しをする必要に迫られた(リンク先でAMDの人がEPYCで問題が起きることを否定している)
さらなる交換
AMDが問題を認めるのと前後して、私にはさらに次の石が送られてくることになりました。今度は私と同じマザーボード、RAMを使った環境を使ってAMDが24時間のテストをしたものです(恐らくはSEGVが起きるgccによる負荷をかけたもの)。幸いにもこの石は私の環境で24時間の負荷テストにパスしたので*5、AMDには、これでOKという回答をしました。
おわりに
発見したときからおよそ3か月以上をかけて、ようやく(私については)問題が解決しました。信頼できるCPUを得たことによって、新マシンでやろうとしていた色々なことがようやくできるようになったので、ほっとしています。これまでのAMDによるサポート対応、Ryzenに問題があると認めたときのコメント内容、および事後処理の方法に色々と言いたいことはあるのですが、私はすでに「正しく動くCPUを手に入れる」という目標を達成したので、あまり深く追求しないことにしておきます。今後AMDがRyzenユーザに誠実な対応をすることを願っています。
おまけ
私は起きるはずのない箇所でGPFが起きてる時点で原因追求をほぼやめましたが、EIRAKUさんというかたがBitVisorというVMMを使ってさらなる解析をしてくださっています。技術的に面白いので興味のあるかたはごらんください。
端的に言うと、問題発生時は、本来実行すべき命令から0x40バイトずれた命令を実行してしまっているらしいということです。私の環境、および他の様々な人々の環境で発生した種々のSEGVの原因はここで書いている論理でだいたい説明できそうです(EIRAKUさんの環境ではまだ謎のケースもあるようですが)。それに加えてこの誤った命令を実行する事象はSEGV以外にもデータ破壊を含めて何が起きても不思議ではないという恐ろしいものであることもわかりました。なぜなら、誤った命令を実行するということは、それをきっかけに直接的ないし間接的に誤った内容をメモリ、及びストレージに書き込むかもしれないからです。
オフライン状態においてWSLでemacsやsudoが起動中に固まる(解決済)
結論
WSLを使うときは次のように/etc/hostsにマシンのホスト名を書くべし。
127.0.0.1 localhost puffy # puffyは私のwindowsマシン名
そうしないとemacs, sudoなどの、実行時にホスト名を解決しようとするソフトが固まる
問題の認識
数日前に買ったノートPCでWSLをしばらく快適に使っていたのですが、emacsが起動中に固まって動かなくなる問題がさきほど発生しました。その後sudoにも同じ問題が起きることがわかりました。つい数十分前には正しく使えており、かつ、その後Windows Updateはしていないし、設定変更もしていないので、これはおかしいです。
トラブルシューティング
最後に問題が発生していなかった時点(今朝9時ごろ)と問題発生を確認した時点(9時30分ごろ)の差分をしばらく考えてみたところ、前者はオンライン環境であり、後者はオフライン環境だったことを思い出しました。ネットワーク環境に関係あるのかを確認するために、オンラインにしてから同じ操作をすると、問題は発生しませんでした。ここで一つ「ネットワーク関係の疑いが強い」という切り分けに成功。
デバッグのためにstrace -o emacs.log emacsを実行すると、次のように/etc/resolv.confをopen(2)したり、uname(2)コマンドでホスト名を取ったりした後に発行した複数回のsenddmsg()にそれぞれ10秒前後時間がかかっていることがわかりました。
emacs.log
... 1492485708.123190 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=189, ...}) = 0 1492485708.123497 open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 3 1492485708.123952 fstat(3, {st_mode=S_IFREG|0644, st_size=189, ...}) = 0 1492485708.124115 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa4fe940000 1492485708.124295 read(3, "# This file was automatically ge"..., 4096) = 189 1492485708.124478 read(3, "", 4096) = 0 1492485708.124648 close(3) = 0 1492485708.124820 munmap(0x7fa4fe940000, 4096) = 0 1492485708.124986 uname({sys="Linux", node="puffy", ...}) = 0 1492485708.125249 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3 1492485708.125475 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.43.1")}, 16) = 0 1492485708.125710 gettimeofday({1492485708, 125750}, NULL) = 0 1492485708.125859 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) 1492485708.126111 sendmmsg(3, {{{msg_name(0)=NULL, msg_iov(1)=[{"t\246\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\1\0\1", 23}], msg_controllen=0, msg_flags=0}, 23}, {{msg_name(0)=NULL, msg_iov(1)=[{"_\200\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\34\0\1", 2 3}], msg_controllen=0, msg_flags=0}, 23}}, 2, MSG_NOSIGNAL) = 2 1492485714.097840 poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout) 1492485719.099159 socket(PF_INET6, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 4 1492485719.099929 connect(4, {sa_family=AF_INET6, sin6_port=htons(53), inet_pton(AF_INET6, "fec0:0:0:ffff::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0 1492485719.100742 gettimeofday({1492485719, 100932}, NULL) = 0 1492485719.101843 poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}]) 1492485719.103170 sendmmsg(4, {{{msg_name(0)=NULL, msg_iov(1)=[{"t\246\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\1\0\1", 23}], msg_controllen=0, msg_flags=0}, 23}, {{msg_name(0)=NULL, msg_iov(1)=[{"_\200\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\34\0\1", 2 3}], msg_controllen=0, msg_flags=0}, 23}}, 2, MSG_NOSIGNAL) = 2 1492485731.096900 poll([{fd=4, events=POLLIN}], 1, 3000) = 0 (Timeout) 1492485734.098345 socket(PF_INET6, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 5 1492485734.099193 connect(5, {sa_family=AF_INET6, sin6_port=htons(53), inet_pton(AF_INET6, "fec0:0:0:ffff::2", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0 1492485734.099969 gettimeofday({1492485734, 100273}, NULL) = 0 1492485734.101202 poll([{fd=5, events=POLLOUT}], 1, 0) = 1 ([{fd=5, revents=POLLOUT}]) 1492485734.102447 sendmmsg(5, {{{msg_name(0)=NULL, msg_iov(1)=[{"t\246\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\1\0\1", 23}], msg_controllen=0, msg_flags=0}, 23}, {{msg_name(0)=NULL, msg_iov(1)=[{"_\200\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\34\0\1", 2 3}], msg_controllen=0, msg_flags=0}, 23}}, 2, MSG_NOSIGNAL) = 2 1492485746.097900 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} --- 1492485746.098406 rt_sigaction(SIGINT, {SIG_DFL, [INT], SA_RESTORER|SA_RESTART, 0x7fa4fc946cb0}, {0x4a6200, ~[RTMIN RT_1], SA_RESTORER, 0x7fa4fd000330}, 8) = 0 1492485746.099849 getpgrp() = 139 1492485746.100944 ioctl(0, TIOCGPGRP, [139]) = 0 1492485746.102129 rt_sigprocmask(SIG_BLOCK, [WINCH IO], NULL, 8) = 0 1492485746.103238 rt_sigaction(SIGIO, {SIG_IGN, [IO], SA_RESTORER|SA_RESTART, 0x7fa4fc946cb0}, {SIG_DFL, [], SA_RESTORER, 0x7f161b466cb0}, 8) = 0 1492485746.104837 exit_group(2) = ? 1492485746.105671 +++ exited with 2 +++
resolv.confの読み出しもuname(2)の発行もホスト名に関するものであり、かつ、sendmmsg()によって送信したメッセージの中にもホスト名を示す文字列(“puffy”)が入っていたので、問題はホスト名の解決に関するものかなと推測しました。
hostnameコマンドは一瞬で"puffy"を返すので問題ないとして、/etc/hostsはどうなっているかを見ると、127.0.0.1にpuffyは結び付けられていませんでした。
/etc/hosts
... 127.0.0.1 localhost ...
これを次のように変更したらオフラインでもうまく動くようになりました。
/etc/hosts
... 127.0.0.1 localhost puffy ...
Windows 10 Creators Updateを適用したらmoshが動くようになった
2, 3日前にWSL上でmoshを動かしたところ、ログインした瞬間にプロセスが終了してしまうという問題が発生しました。ぐぐったところ、既知の問題でした。
上記Issueを追ってみると、Creators Updateを適用すると直るとのことなので早速適用してみると、うまく動きました。やったぜ。
Windows UpdateによってSIMの通信規制された&対策をとった
最近、数年ぶりにWindows PCを買いました。モバイルノートなので、どれくらいバッテリが持つものなのかを試すために、外出先でテザリングによって通信しながらバッテリが切れるまで作業しました。すると、ある時点から通信が極端に遅くなってしまいました。なぜかと思ってスマホの通信量を確認すると、案の定、一日あたりの通信規制にひっかかる通信量を超えていました。あーあ。
きっとWindows Updateの自動ダウンロードの仕業だろうと思って、Windows Updateの設定から自動ダウンロードを無効化しようとするも、そういう設定はありませんでした。但し書きを見たところ、
利用可能な更新プログラムが自動的にダウンロードされ、インストールされます。従量制課金接続(料金が発生する場合があります)では実行されません。
と書いてありましたが、どうやって従量制課金接続かどうかを判定しているのかは不明でした。
調べた結果、wifiの設定の中でアクセスポイントごとに従量制課金接続かどうかを設定できるようです。具体的には次の設定項目です。
設定 → ネットワークとインターネット → wifi → <AP名> → 従量課金制接続として設定する
これを設定したら通信量の急激な増加が収まったので、おそらくWindows Updateが原因という仮説も正しかったのでしょう。
さくらVPSから無期限無料で使えるGCEインスタンスへ乗り換えた
私は、さくらVPS(1GBプラン)を数年間使ってきました。昔はこのサーバを多種多様な用途に使っていたのですが、最近では一部を除くほとんどの機能は無料で使える、他者が提供するwebサービス(github, qiita, はてなブログなど)に移行してしまいました。
現在の用途は次の通りです。
- 公開webサイト(ほぼ静的コンテンツ)の提供。アクセス数は一日に数百程度と、非常に少ない
- 自宅の計算能力の高いマシンのインターネット側IPアドレス(非固定)の記録: インターネットから自宅マシンに接続するために必要。
- ホームティレクトリ以外のシステム領域の変更も含めた種々の実験。動作確認程度なのでCPU性能は必要ない
用途がこれだけになったことによって、元々それほど性能が高くない上記VPSであっても、要求スペックに対する価格が若干上回ってしまっていました。そのため、次のような要求仕様のマシンをしばらく探していました。
- 1サーバを専有できる
- 静的IPアドレス
- CPU性能はほとんど必要ない
- メモリはUbuntuの要求仕様の最低である512MBもあれば十分
- ストレージは20GB程度あればOK。HDDかSSDかは問わない
- 現在のVPS(年間一万円強)より安価
その最中、無期限無償で使えるGCEインスタンスの存在を知りました。このインスタンスについては過去に以下のエントリで触れました。
satoru-takeuchi.hatenablog.com
このインスタンスはCPUとメモリのスペックが非常に低いのですが*1、ここ最近色々と評価した結果、私の用途では一応要件を満たすことを確認しました。VMインスタンス以外にも通信料と固定IPアドレスに関して課金要素がありますが、通信料については枠内に収まりそうですし、静的IPアドレスについては、マシンの電源を落とさなければ課金されない、かつ、落とすつもりはないので問題ありません。
本日移行したところ、移行そのものはあっさり終わって(待ち時間を含めて4,5時間)、いまのところ問題なく動いています。元々は、「今のところより安いものがあればいいな」程度に思っていましたが、まさか無料になってしまうとは思いませんでした。これだけのものが無料で使えるというのは凄いと共に、恐ろしいものです。今後はサービス規約の変更が無いかを注意深く観察しながら、しばらく使ってみようと思います。