前回紹介した SystemTap は、システムの管理や保守を行う人にとってだけでなく、Linux カーネルの開発やシステムの開発を行う人にとっても有用なツールです。 SystemTap を使うと、任意の箇所に遅延を挿入したり、メモリーの内容を書き換えたりすることもできます。そのため、意図的に競合状態を発生させることで問題事象を再現させたり、意図的にエラー状態を発生させることでトラブルが生じないかどうかを試験したりすることができます。そこで、今回は SystemTap を用いて試験を行った事例について紹介したいと思います。

ここで紹介している内容は、トラブル発生時の対処フローを確認したい場合に試すことができます。例えば、フリーズ事象が発生した場合には、 SysRq キーを使って情報を取得する練習ができます。

また、 KernelOops イベントが発生した場合に備えて、 /proc/sys/kernel/panic_on_oops に 1 を設定して kdump サービスを開始しておくことにより、 kdump を取得して問題を解析する練習ができます。今までの連載で紹介したトピックを活用しながら挑戦してみてください。

使い方1：不整合状態を検知したり発生させたりする。

RHEL 6 において原因不明のカーネルパニックが発生するという事例報告が Red Hat 社のサイトにありました。（ https://access.redhat.com/solutions/640843 ）この問題に悩まされていたお客さまからの相談を受け、カーネルのソースコードを調査してみたのですが、不審な点は見つかりませんでした。
そこで、矛盾が発生したらすぐにカーネルメッセージを出力するように、以下のように SystemTap スクリプトをお客さまのシステムに仕掛けた状態で試験をしていただきました。

---------- コマンドライン　ここから ----------
# stap -g -e 'probe kernel.function("start_thread").return {
%{ WARN(tsk_used_math(current) && !((struct fpu *) &current->thread.xstate)->state, "tsk_used_math(current) != 0") %};
---------- コマンドライン　ここまで ----------

矛盾が発生しない限り、このスクリプトがメッセージを出力することはありません。
しかし、驚いたことに、カーネルパニックが発生する前に、このスクリプトによるメッセージが出力されていました。つまり、このスクリプトにより、矛盾が発生していることと、その発生タイミングが execve() システムコールの実行中であることが判明した訳です。
しかし、カーネルのソースコードを再調査したものの、矛盾が発生する余地は見当たりませんでした。
そこで、より正確な発生箇所を割り出すために、以下のように別の SystemTap スクリプトを仕掛けた状態で、再度試験を行っていただきました。（このスクリプトは挿入位置をアドレスで指定しているので、RHEL 6 の 2.6.32-358.23.2.el6.x86_64 カーネル以外では動きません。任意の箇所にフックを仕掛ける例として考えてください。）

---------- カーネル 2.6.32-358.23.2.el6.x86_64 用のコマンドライン　ここから ----------
# stap -g -e '
function check_status() %{
  WARN(used_math(), "used_math() is set with current->thread.xstate=%p\n",
       current->thread.xstate);
  WARN(sigismember(&current->pending.signal, SIGSEGV), "SIGSEGV is pending\n");
%}
probe kprobe.statement(0xffffffff811d9744).absolute /* fs/binfmt_elf.c:735 */ { check_status(); }
probe kprobe.statement(0xffffffff811d9856).absolute /* fs/binfmt_elf.c:761 */ { check_status(); }
probe kprobe.statement(0xffffffff811da7a1).absolute /* fs/binfmt_elf.c:790 */ { check_status(); }
probe kprobe.statement(0xffffffff811d997f).absolute /* fs/binfmt_elf.c:825 */ { check_status(); }
probe kprobe.statement(0xffffffff811d99eb).absolute /* fs/binfmt_elf.c:855 */ { check_status(); }
probe kprobe.statement(0xffffffff811d9bc3).absolute /* fs/binfmt_elf.c:877 */ { check_status(); }
probe kprobe.statement(0xffffffff811d9c04).absolute /* fs/binfmt_elf.c:895 */ { check_status(); }
probe kprobe.statement(0xffffffff811d9e48).absolute /* fs/binfmt_elf.c:916 */ { check_status(); }
probe kprobe.statement(0xffffffff811da7c1).absolute /* fs/binfmt_elf.c:929 */ { check_status(); }
probe kprobe.statement(0xffffffff811dd3aa).absolute /* fs/binfmt_elf.c:948 */ { check_status(); }
probe kprobe.statement(0xffffffff811dd41f).absolute /* fs/binfmt_elf.c:953 */ { check_status(); }
probe kprobe.statement(0xffffffff811dddd3).absolute /* fs/binfmt_elf.c:957 */ { check_status(); }
probe kprobe.statement(0xffffffff811dde53).absolute /* fs/binfmt_elf.c:966 */ { check_status(); }
probe kprobe.statement(0xffffffff811dde72).absolute /* fs/binfmt_elf.c:969 */ { check_status(); }
probe kprobe.statement(0xffffffff811ddea8).absolute /* fs/binfmt_elf.c:977 */ { check_status(); }
probe kprobe.statement(0xffffffff811ddeb8).absolute /* fs/binfmt_elf.c:991 */ { check_status(); }
probe kprobe.statement(0xffffffff811d9581).absolute /* fs/binfmt_elf.c:1009 */ { check_status(); }
probe kernel.function("start_thread") { check_status(); }
probe kernel.function("start_thread").return { check_status(); }

function check_signal(sig:long, task:long) %{
  WARN(current->in_execve, "force_sig_info() is called with signal=%u pid=%u\n",
       (unsigned int) STAP_ARG_sig, ((struct task_struct *) STAP_ARG_task)->pid);
%}
probe kernel.function("force_sig_info") { check_signal($sig, $t); }

probe kernel.function("fpu_init") {
  %{
    WARN(current->in_execve,
         "fpu_init() is called with used_math()=%u current->thread.xstate=%p\n",
         used_math(), current->thread.xstate)
  %};
}'
---------- カーネル 2.6.32-358.23.2.el6.x86_64 用のコマンドライン　ここまで ----------

このスクリプトにより、本来は flush_thread() 関数内でクリアされているはずの PF_USED_MATH フラグがクリアされていないことが判明しました。そこで、フラグが操作される箇所を洗い出してみたところ、お客さまのシステムで使用している cpuset cgroup 機能の中に、スレッドセーフではない処理がありました。そこで、競合状態をエミュレーションするために、以下のように SystemTap スクリプトを仕掛けた状態で手元の環境で実験したところ、事象を再現させることに成功しました。

---------- コマンドライン　ここから ----------
# stap -F -g -e 'probe kernel.function("flush_thread").return { if (execname() == "su") { %{ current->flags |= PF_USED_MATH %}; exit(); } }'
# ulimit -c unlimited; su -c "echo hello"
---------- コマンドライン　ここまで ----------

この不具合は Linux 2.6.31 で混入し、 Linux 3.17 で修正され、 2.6.32-504.8.1.el6 および 3.10.0-210.el7 にも修正がバックポートされました。
（ https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/?id=2ad654bc5e2b211e92f66da1d819e47d79a866f0 ）
不整合状態の発生条件が命令の実行タイミングに強く依存していたことと、不整合状態が発生してからシグナルを受信するまでの処理の流れを kdump の情報から追うことができないケースという特殊さが組み合わさって、不明瞭なカーネルパニックを引き起こしてきました。お客さまが事象の再現手順を確立し、 SystemTap による調査を容認していただけたからこそ、この不具合を見つけることができました。（再現手順を確立することの重要性は、 Bugzilla ノススメ で紹介した通りです。）

使い方2：メモリー割り当て要求を失敗させる。

Linux システムでは、 OOM killer の発生時にデッドロックが発生して、システムの応答が無くなったままになってしまうという事象が発生します。そして、予期せぬ再起動やハングアップの原因が、想定外の負荷がかかってメモリー枯渇状態に陥り、 OOM killer 発生時のデッドロックによりプロセスが動けなくなっていたからという現実のトラブル事例が散見されます。この事象が発生する理由が昨年末に明らかになった（ http://lwn.net/Articles/627419/ ）のですが、 Linux カーネル開発者はこの事象をどうやって修正すべきなのかで悩んでいる最中です。というのも、

1. カーネルのメモリー管理サブシステムは、メモリー割り当てを待つことが可能な状況かつ __GFP_NORETRY が指定されていない32キロバイト以下のメモリー割り当て要求であれば、 OOM killer により選択されない限り、空きメモリーを確保できるようになるまで永遠に待ち続ける。
2. カーネルのメモリー管理サブシステムを利用する側は 1. の挙動を想定していない。言い換えると、空きメモリーを確保できるようになるまで永遠に待ち続けるのではなくメモリー割り当て要求が失敗することを前提としてロックの獲得処理を行っている。
3. OOM killer により選択されたスレッドが速やかに終了できるようにするために、 OOM killer が選択したスレッドは非常時のために予約していたメモリーから割り当てを行えるという配慮がされている。そのため、カーネルのメモリー管理サブシステムを利用する側が 1. で OOM killer に選択されたとしても、実際にメモリー割り当て要求が失敗することは滅多にない。
4. 非常時のために予約していたメモリーが 3. の配慮により枯渇しないように、カーネルのメモリー管理サブシステムは、 OOM killer が選択したスレッドが終了するまでは別のスレッドを選択しない。そのため、 OOM killer が選択したスレッドがロックの獲得待ちなどにより終了できなかった場合、誰かがメモリーを自発的に解放しない限り、永遠に空きメモリーを確保できないデッドロック状態が発生する。
5. カーネルのメモリー管理サブシステムを利用する側にはメモリー割り当てが失敗した場合に実行されるエラーハンドリング処理が用意されているが、 1. および 3. により割り当て要求が失敗してこなかったために、エラーハンドリング処理の大部分は一度もテストされていない。そして、 2. および 4. によりデッドロック状態が発生するのだが、デッドロックが発生したことを誰も検知できないため対処できない。
6. エラーハンドリング処理をテストするために、メモリー割り当てをランダムに失敗させるフォールトインジェクション機能があるが、全てのエラーハンドリング処理がテストされるように意図したタイミングで失敗させることが難しい。

というややこしい状況にあるためです。 1. の挙動を変更して永遠に待たないようにすれば 5. のエラーハンドリング処理が使われるようになり、不明瞭な不具合が多発することが予想されています。そこで、 1. の挙動を変更するとどのような不具合が起こるのかを実験するために、以下のように kmalloc() 関数による全てのメモリー割り当て要求が1回ずつ失敗する状況を SystemTap を使うことで再現してみようと思います。（ https://lkml.org/lkml/2014/12/25/64 ）

---------- fault_injection.stp　ここから ----------
global traces_bt[65536];
probe begin { printf("Probe start!\n"); }
probe kernel.function("__kmalloc") {
  if (($flags & %{ __GFP_NOFAIL | __GFP_WAIT %} ) == %{ __GFP_WAIT %} && execname() != "stapio") {
    bt = backtrace();
    if (traces_bt[bt]++ == 0) {
      print_stack(bt);
      printf("\n\n");
      $size = 1 < 30;="" }="" }="" }="" probe="" end="" {="" delete="" traces_bt;="" }="" ----------="" fault_injection.stp　ここまで="" ----------="" />

---------- コマンドライン　ここから ----------
# stap -p4 -g -DSTP_NO_OVERLOAD -m stap_fault_injection fault_injection.stp
# staprun stap_fault_injection.ko
---------- コマンドライン　ここまで ----------

実際にこの試験を行うと、初期化途中のデータ構造体を解放しようとしてフリーズが発生 （ https://lkml.org/lkml/2015/1/9/281 ）したり、メモリー破壊によるカーネルパニックが発生（ http://lists.freedesktop.org/archives/dri-devel/2015-January/075922.html ）したりと、ほぼ間違いなくトラブルに巻き込まれることでしょう。

他にも kmem_cache_alloc() や vmalloc() や __get_free_pages() などのメモリー割り当て関数が存在しており、全てのケースをテストして不具合を解消するのは非現実的であると考えられるため、別のアプローチを検討する必要がありそうです。

（半田哲夫）

コーヒーブレーク「オフとオン」

前々回のコラム で紹介した HP200LX ですが、長年放っておいた間に問題が発生したようで、通常であれば数週間持つはずの電池が数時間で消耗してしまいます。残念ですが利用をあきらめました・・・、ではなくここは「大人の特権」を発動するところデス！ということで、オークションで落札したものを持ち歩いています(予備機まで購入しました)。システムマクロでフラッシュカードに自動保存していたデータから、予定表のデータを復元したところ、最後に使用していたのは 1997 年 11 月と判明しました。連絡先を含め、 18 年前の環境がレジュームし、更新を再開しました。

復元したデータの中に FHPPC の巡回データが残っていました。FHPPC とはニフティサーブのフォーラムのひとつです。記事に書いたように、当時は従量課金だったので、オフラインでメールやメッセージを書いて、モデムで接続、届いたメールや新着メッセージをダウンロードしてゆっくり読むというスタイルです。

自宅でも外出先でも常時接続が当たり前になっている現在、読者の方々もニフティサーブやパソコン通信の名前を聞いてもわからない方がほとんどと思います。そうした方々にとっては、オフとオンを組み合わせるスタイルはいかにも古くさくて、不便、この記事を書いている私は化石的存在、そのように映るのではないかと思います。(ほっておいてください)
でも私はそこに疑問を感じています。

「効率」、「最新情報を得る」という観点からは、常時接続が優れているのは明らかというか当たり前です。ただ、本当に効率や最新の情報が重要でしょうか？そうして集めた情報を活用できるのでしょうか？その終わりなき追求の先には、安らかな境地が待っているのでしょうか？

本コラムのタイトルは、「オンとオフ」ではなく「オフとオン」としました。それは、オフ(ライン)がベースで、時々オン(ライン)で更新(同期)する、という意味です。オフの時間は、新たな情報は入りません。自分がペースをコントロールする時間であり、言ってみれば、自分が主役の時間です。常時接続の世界には基本的にこの自分が主役の時間がありません。

ひとつ例をあげます。個人やグループの連絡に活用されている SNS にLINE があります。電車の中でもよく着信音を聞いたり画面を見かけたりします。常時接続の世界なので、まさに絶え間がありません。私自身は利用していませんが、他人事ながら「これで神経が休まる時があるのか」と心配になります。既読未既読の状態表示機能もあるということですが、読んでいる状態まで監視されるのは個人的には勘弁です。Twitter や Facebook は私も利用しています。それらを便利なツールだと思いますが、あくまで使いこなせるだけの経験や能力があってのことです。人生経験が浅い、多感な世代の利用には慎重になるべきだと思います。「オフ」と「オン」があった時代、初心者はフォーラムなどの場で、暮らし方、他のユーザーとのつきあい方を学びました。きびしさの中にぬくもりを感じる、そんなところがありました。最初から世界につながるインターネットは、自由ですが自己責任を求めている部分があると感じます。

ニフティサーブは2009年にサービスを終了しました。限定公開されていたコミュニティサイト、メモリアルサイトも2014年5月に終了しています。もうそこに帰ることはできませんが、忘れ物を探すことはできるかもしれません。

ところでご案内が遅れましたが、本コラムの記事には、 Twitter と Facebook のボタンが配置されています。よろしければ是非お願いいたします（さかのぼって）。

（原田季栄）

• Hinemos関連サービス
• Hinemos