Open Source Summit Japan 2017に参加してきました

Open Source Summit Japan 2017というオープンソースソフトウェアに関する様々なセッションを聞くというイベントに昨日まで三日間参加してきました。内容を覚えてるうちにメモしておこうと思います。

Open Source Summit Japan 2017 | Open Source Summit Japan 2017 | Linux Conferences and Linux Events | The Linux Foundation

このイベントについて全然知らない人のために補足しておくと、世界中から様々な人が集まってくる全編英語の国際イベントです。参加人数はぱっと見、千人前後でしょうか。今年はとくにたくさんの人が参加したようです。かつてはLinux Con Japanという名前でlinuxカーネルを中心としたlinuxの話が主だったのですが、最近は他のOSSのセッションが増えてきてlinux色が薄まってきたからなのか、今年から改名したようです。

セッションそのもの以外でも、ここ数年は学生さんが多く参加しており*1、別の学生達や職業エンジニアの知り合いを作ったりという、同好の士を繋ぐハブとしての役割も果たしているように見えます。私も今年10人程度の学生さんを含むエンジニアと新たに知り合い、かつ、SNS上でしか知らなかった方々と初対面を果たせました。

ここからは今回とくに印象に残った二つのセッションについて紹介します。主にわたしが個人的に気になった部分の簡単な紹介や、それについて私がどう思ったか、どういう質疑があったのかということを書きます。詳しい内容は既にアップロードされている(かつこのエントリにリンクを張っている)セッションのスライドに書いているので、そちらを見ていただければと思います。

Noah: Hypervisor-Based Darwin Subsystem for Linux - Takaya Saeki & Yuichi Nishiwaki, The University of Tokyo

sched.co

スライドはこちら

LinuxのバイナリをmacOSの上で動かすという話です。「*BSDにもWindowsにもLinuxバイナリを動かす方法があるのにmacOSには無い、作っちゃえ!」という面白い動機によって開発されたようです。ネタがネタだけに会場には馴染みのあるカーネル野郎達がウジャウジャいました。類は友を呼ぶというやつでしょうか。

実現方法はおおよそ次の通りです。

  1. 1つのlinuxバイナリを動かすごとに1つのVMを立ち上げてそこにバイナリをロードする。および、後述のNoahプロセスというプロセスを立ち上げる
  2. linuxバイナリから作ったプロセスが発行するシステムコールはハイパーバイザがすべてトラップする
  3. システムコールの依頼内容をハイパーバイザがNoahプロセスに転送
  4. Noahプロセスがシステムコールをエミュレーションして結果をLinuxバイナリから作ったプロセスに返す(ちょうど普通のハイパーバイザがguestのかわりにハード処理をするようなイメージ)

Noahプロセス自身は単なるユーザプロセスなので、エミューレーション用コードにバグがあっても*BSDWIndowsによる他の実現方法のようにカーネルパニックが発生しないという特長があります。他にもmacOSのプロセスとLinuxバイナリから作られたプロセスがパイプやシグナルで通信できるという特長もあるようです。すごい。

話を聞いていると確かに技術的に言ってることは理解できるのですが、そのアイデアを実装して形にしてしまう行動力、および、あまたあるシステムコールのエミュレーションコードを書いて実装を完成させて動くところまでもっていくという実装力に感心しきりでした。

他にも質疑が面白かったのも特徴的でした。この手のネタはエンジニアにとってはどれだけの種類のLinuxバイナリが動くのか、つまりどこまでの範囲Linuxをエミュレーションできているのかという興味が尽きないのですが、「コンテナは動かしたことあるか」「procfsはどうなっているのか」という質問に対して彼らはことごとく「Please send PR」というカウンターパンチを使って見事切り抜けていました。発表中にとっさにこういうウィットに富んだことが言えるのもポイントが高いです。

余談ですが、発表されたおふたりはNoahで未踏スーパークリエイター認定を受けた方々だそうです。すごい人もいるもんですね。

www.ipa.go.jp

WalB: Real-time and Incremental Backup System for Block Devices - Kota Uchida, Cybozu, Inc.

sched.co

スライドはこちら

サイボウズ社が運用しているシステムにおけるバックアップの課題と、それを解決したWalBというバックアップシステムの紹介です。サイボウズグループウェア日本最大手であり*2、この規模の会社が使っているシステムの内部を数値込みで見られることはなかなか無いので、貴重な機会でした。

サイボウズのシステムでは一日一回のインクリメンタルバックアップが要件になっているそうです。dm-snapやdm-thinなどを用いたバックアップシステムでは(既存システムはdm-snapを用いたもの)、一日ごとにスナップショットを採取して、最新のものから数えて2つのスナップショットをスキャンすることによってバックアップ用の差分をデータを作る必要があります。これらの方法ではこのスキャン処理にかかる時間が長いのがネックなのだとか。

その一方でWalBは、管理対象とするブロックデバイスに対する書き込みのログ(デバイス内のどこに何を書き込んだかという情報)をログデバイスと呼ばれるデバイスに別途書き込んでおいて、このログがほぼそのままインクリメンタルバックアップ用の差分データになるという仕組みだそうです。この方法だと書き込み処理ごとに定常的にログデバイスに対する書き込みが発生しますが、スナップショットベースのバックアップシステムのような、一日一回バックアップ時に発生する大きなI/O負荷(スキャン処理)は無くなります。うまく考えたものです。

今回はバックアップを採取する側の話が中心でしたが、今後はリストアを含めた運用全体に関する話がどこかで聞けたらいいなあと思いました。

このセッションについては、技術的な面白さだけではなく、ハードを売っているわけでないソフトウェア専業の会社がlinuxデバイスドライバ(WalBのブロックデバイスを実現する部分)を書いて、バックアップシステムを自作して、かつ、それを実運用していることにも感銘を受けました。最近ではFacebooklinuxカーネルチームを抱えているなど、海外企業ではそのような事例はいくつも聞いたことがありますが、日本でもこういうことをしている会社があるのは知らなかったです。

なお、このプレゼンは再演予定もあるそうなので、興味のある人は行ってみるといいかもしれません。

atnd.org

*1:まだ学生でなく生徒と呼ばれる年齢のかたもいらっしゃいます。すごい

*2:このエントリを読んでくれるようなエンジニアの人にとっては、最近話題になった、32GBメモリのマシンを全員に支給してくれる羨ましい会社としてのほうが有名かも

コーディング練習: holeを意識したコピー

昨日に引き続きプログラミングの練習。網羅性とサイズの大きさで有名な次の本の演習のひとつを扱いました。

作るのはファイルをコピーするだけのプログラムです。もとのファイルにholeがあれば、コピー先ファイルにもholeを作る必要があります(ヌルバイトの連続によってストレージ領域を消費してはいけない)。

web上には次のような回答例がありました。

github.com

目的のプログラムを作る場合には通常lseek()のwhence引数にSEEK_HOLEとSEEK_DATAを指定することによってholeのありかを検出します(ここには書きませんがioctl()でも同様のことができます)。しかし、上記プログラムの作者の環境はこれらが使えないカーネルバージョンだったらしく、この方法を使わない単純な実装になっていました。連続するヌル文字を見つけたら、それらをただ書き込むのではなく、lseek()によって飛ばしてしまおうというものです。これは一見うまくいきそうですが、次のような問題があります。

  • もともとわざとヌル文字で埋めていたブロックもholeになってしまう
  • hole部分をフルスキャンする必要があるため、コピー所要時間が長くなる
  • ファイル末尾に連続するNULL文字あるいはholeがあった場合は、その部分がコピーされない。それら領域をlseek()によって飛ばした後に0バイトwrite()する(つまり実質何もしない)だけでファイルサイズを正しいものに更新しないため、ファイルサイズがコピー元ファイルより短くなってしまう

実際、次に示す簡単なテスト(ファイル内の色々な箇所にholeが空いているファイルをコピー)のほとんどに失敗しました。

github.com

その一方で、私の実装は次の通りです(上記プログラムは見ずに作ってます)。

github.com

このプログラムは、次のような特徴があります。

  • lseek()におけるSEEK_HOLEとSEEK_DATAを使っている。データ領域をコピーする処理と、その後に続くholeを飛ばす処理の繰り返しです。
  • エラー処理のためにgotoを用いている。gotoを見るのも嫌というかたがたもいると思いますが、こういうケースではgotoを使わないほうがむしろコードが見にくくなると私は考えています

こちらは前述のテストをすべてパスしました。ほかの観点でテストをしたらまだバグは潜んでいると思いますが、ひとまずは合格です。

コーディング練習: 人の書いたプログラムを自分の方法で書き直す

web上で、とある凄腕エンジニアのかたが実装した簡単なプログラミング言語の実装と、その様子を紹介したビデオを見つけました。

gist.github.com

www.youtube.com

思うところあって、プログラムの仕様をできるだけ変えないまま、自分なりに書き直す練習をしたかったので、ちょうどいい小さな規模のこのプログラムで実践してみました。

gist.github.com

仕様を変えないまま…とは言っても仕様が文書なりで明確化されていたわけではないので、ソースから著者の意図を推測しただけです。一から書き直すという方法もありますが、今回は既存のソースを改編するという方法をとりました。

変更点は次の通り。

  • 仕様っぽいもの(すごく柔らかい、お金を取るプロダクトの仕様書として出したら殴られるレベルのもの。ここではこれでいいんです)をソース冒頭に書いた
  • 関数名、変数名(とくにグローバル変数)は何をしているものなのかをわかりやすくした
  • エラーチェックの追加: 引数の数、バッファオーバーランなど
  • print機能(P()関数)による出力と、トップレベルの文を評価した際の出力を区別できるようにした
  • 雑多なバグ修正

もう少しこだわると、コードへのポインタはグローバル変数ではなく関数引数にしたかったんですが、無用にややこしくするだけになる恐れがあったので、やめました。

可読性においては初級者には見やすくなっていると思います。その一方で、上級者にとっては冗長に見えるかと思います。それらはオリジナルソースの作者と私の好みの違い、および、ソースをどれだけ気合を入れて書いたかの違いでしょう。「俺だったらここはこうするね」という意見も多々あろうかと思います。色々な人が同じことをした場合のソースを並べて見てみたいものです。

この試みはけっこう面白かったので、他のソースでもやってみようかと思います。オレオレプログラムを書く場合とは異なる脳の部位を使っている気がします。

ノートPCに仕込まれていたキーロガーを削除した

三日前にこんなニュースが飛び込んできました。

thehackernews.com

で、私が最近買った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つの問題

NOTE: 2017/7/14に更新しました。2つある問題のうち、1つ目はほぼ解決ですが、2つ目は依然調査中です。

最近Ryzenを積んだデスクトップマシンを買いました。その上で日課であるカーネルビルド&テストをした*1ことをきっかけに、2つの問題が発生しました。先代のCore i5を積んだマシンでは起きなかった現象です。

このエントリは自分用のメモがてら、新しいことがわかれば随時更新していきます。

環境

ハードウェア

  • CPU: Ryzen 1800X
  • Motherboard: ASUS PRIME X370-PRO
  • BIOS: 1.0.0.4a(設定はSVM以外デフォルト)
  • DIMM: Kingston KVR24N17S8/8 * 4 (8 * 4 = 32GB)
  • GPU: GeForce GTX 1060

ソフトウェア

  • OS: Ubuntu 16.04
  • kernel: 4.8.0-54-generic
  • gcc: gcc (Ubuntu 5.4.0-6ubuntu1~16.04.4) 5.4.0 20160609

問題1: VM上でAVX2命令を実行した時に不正な命令を実行したとみなされる

要約

[原因]

  • qemuのデフォルト設定ではRyzen(というかZenアーキテクチャ)をうまく扱えず、AVX2命令に対応していないCPUだと認識されてしまう

[対策]

[回避方法]

  • “詳細"に記載の方法でqemuないしlibvirtに所定のオプションを設定する

詳細

ブート時のカーネルのログはこんなかんじ。

...
[    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カーネルのいろんなコンポのメンテナ)からレスをいただき、彼のの環境で再現もできました。かつ、AMDRyzen Engineering Teamにも転送されたようです。

その後Masami Hiramatsuさん(kprobesのメンテナ)から、VMに見えているCPUのモデルと機能フラグの組み合わせの問題では、という指摘を受けました。

www.spinics.net

自分の環境では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のerrataの可能性が高い。しかし、たまたま一部の人が不良品を引いたか、あるいはチップセットなどの他のハード障害の可能性もまだ0ではない。少なくともソフトバグではなさそう。
  • 何らかの理由によりcall(サブルーチン呼び出し)命令発行時に本来のものより0x40低位アドレスの命令を実行してしまう。0x40はキャッシュライン長に一致するので、命令キャッシュの扱いに何等かの不具合があるのかもしれない

[影響]

  • 現在知られているのはSEGV(発生するとプログラムが異常終了するので検知しやすい)によるプログラムの異常終了。誤ってどのような命令を実行するかによって、SIGILLやデータ破壊が発生する可能性もある。

[発生契機]

  • linux, あるいはWindows Subsystems for Linux(WSL, 後述)上でgccを使った場合(コンパイルするソースは何でもよい)。linuxカーネルなど、大規模なプロジェクトのビルドにおいて主に事例が報告されている。これはビルド時間が長いので発生確率も高いためだと考えられる
  • 並列ビルドしなくても単一コア(or スレッド)上のコンパイルで発生する
  • 現在わかっている範囲ではgcc on linuxに限らず、どんなOS上のどんな実行ファイルにおいて発生しても不思議ではない(根本原因が明らかになれば発生環境が限定されるかもしれない)
  • LinuxWindowsにおいて、gcc以外の実行でもこの事例という疑いのある事象がいくつか報告されているが、確証は無い。NetBSDにおいてはほぼ間違いなくこの問題であろうという事象がgccの実行中に発生している

[影響範囲]

  • 不明
  • 筆者の観測範囲では日本だけでも10名以上、海外含めると20名以上の環境(CPU)で発生している
  • 問題が起きる人は長時間ビルドすれば確実に事象が再現できるものの、長時間ビルドしても全く問題が起きていない人もいる(両者の比率は不明)。起きない人はたまたま起きないSW/HW設定なのか、それともこの問題が一部不良CPUに限ったものなのかは不明。

[修正]

  • いまのところ無し。良品への交換、あるいはerrata修正に期待か
  • この問題が発生している人は後述の方法でAMDにサポートリクエストを発行すると個別対応してくれる。筆者は交換対応になったが、リクエスト発行した人全員がそうなるかは不明

[回避方法]

  • 不明
  • 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の問題でない」と考えていた理由をここに書いておきます。指摘には主に二種類あったので、それぞれについて反論の形で記載します。

  1. gccRyzenに対応してないコードなんじゃないの? => 私を含めた、この問題を再現した複数人はdistroが提供するgccを使っています。distro提供のgccは(他のパッケージもですが)、よほど古いものを含めてどんなCPUでも動作するようなコード-でできています。仮にRyzenで動かないコードがあっても、同じ再現試験をすると完走することはなく必ず同じところで失敗するはずです(さらにこれはSEGVとは別の大きなCPU障害です)。仮にRyzenに対応したコードになっていたとしても、それはgccの速度が向上するだけです。
  2. 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上を調査したところ、問題認識当初は無かった、同じ問題についての報告する次のようなスレッドがサポートコミュニティにできていることがわかりました。

community.amd.com

ここで「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が発生する理由が謎

詳細については上述のサポートフォーラムに記載していますので、そちらをごらんください(“2017/06/10 16:42"の投稿)。

よりよい再現プログラムを目指して

これまでの情報をもとに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は1.0.0.6a

現在のところの試験結果は次の通りです。

  1. ランダムなSEGVは発生しなくなった

  2. ランダム(早ければ10分程度、遅いと数時間)にシステムがハングアップする。その際ディスプレイ信号が無くなっており、復旧にはリセットが必要

  3. 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"とは書いていますが、これだけ頻繁に出ると、まともな状態には見えません。

今のところSEGVが起きていないのは嬉しいのですが、MCEとハングアップという2つの問題が新たに出てきたこと、さらにこれが他の人の報告とかなり違っていることより、これをどう解釈したものか頭を悩ませています。

いまのところはAMDに次のことを問い合わせ中です。

  1. 解決のために、次に何をすればいいのか(このMCE多発の正確に意味するところはAMDにしかわからない)
  2. この問題の再現試験をしたのか。既に再現したCPUは私のものを含めてそちらにいくつか届いているはずである
  3. bがyesならば、(可能であれば)結果を教えてほしい

おまけ

私はjmpでGPFが起きてる時点で原因追求をほぼやめましたが、EIRAKUさんというかたがBitVisorというVMMを使ってさらなる解析をしてくださっています。技術的に面白いので興味のあるかたはごらんください。

日記 (2017 年 6 月下旬)

端的に言うと、問題発生時は、本来実行すべき命令から0x40バイトずれた命令を実行してしまっているらしいということです。私の環境、および他の様々な人々の環境で発生した種々のSEGVの原因はここで書いている論理でだいたい説明できそうです(EIRAKUさんの環境ではまだ謎のケースもあるようですが)。それに加えてこの誤った命令を実行する事象はSEGV以外にもデータ破壊を含めて何が起きても不思議ではないという恐ろしいものであることもわかりました。なぜなら、誤った命令を実行するということは、それをきっかけに直接的ないし間接的に誤った内容をメモリ、及びストレージに書き込むかもしれないからです。

*1:私はlinuxカーネル開発者です

*2:アドレスが実行ごとにばらばらなら、特定アドレスの値を変えたりする攻撃が通じなくなる

*3:余談ですが、WSLにおけるこの事象は、なぜかASLRを無効化しても発生します。ASLRの実装が違うことが関係していると推測しています

*4:Windowsにおいては一般保護例外

オフライン状態において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.1puffyは結び付けられていませんでした。

/etc/hosts

...
127.0.0.1 localhost
...

これを次のように変更したらオフラインでもうまく動くようになりました。

/etc/hosts

...
127.0.0.1 localhost puffy
...

Windows 10 Creators Updateを適用したらmoshが動くようになった

2, 3日前にWSL上でmoshを動かしたところ、ログインした瞬間にプロセスが終了してしまうという問題が発生しました。ぐぐったところ、既知の問題でした。

github.com

上記Issueを追ってみると、Creators Updateを適用すると直るとのことなので早速適用してみると、うまく動きました。やったぜ。