第11回「 strace ノススメ」


今回は、プログラムが期待通りに動作しない場合に、特定のプロセスの挙動を追いかけるための手順について紹介します。

プロセスの挙動を追いかける方法にはいろいろあります。例えば、スクリプト言語で記述されたプログラムの挙動を追いかける場合、デバッグのための print 命令を挿入することもあるでしょう。でも、プログラムの種類によらずに挙動を追いかける場合、原則としてカーネルが提供する機能を使います。例えば strace コマンドを用いてシステムコールの呼び出し履歴を取得したり、 ltrace コマンドを用いてライブラリ関数の呼び出し履歴を取得したりします。また、対象となるプロセスが不明な場合には全プロセスを対象にするために System Call Auditing を使って履歴を取得したり、 SystemTap を使って任意の箇所で履歴を取得したりすることもあります。

今回は strace コマンドについて取り上げますが、プロセスの挙動を追いかける上では、その挙動を再現する手順を確立できていることが重要です。 Bugzilla に不具合を報告する際に再現手順が必要であるように、 strace コマンドで追跡する場合も再現手順を確立できないと話が始まりません。

また、ログを時刻情報付きで保存することも重要です。 strace コマンドを用いて情報を取得する場合に限らず、問題事象が発生した正確な日時を伝えることは、的確な対応を行う上で欠かせません。問題事象が初めて発生した時には十分な情報を取得できなかったとしても、数か月経って問題事象が再発した時に前回の情報と照合しながら調査していくというケースもあります。また、問題事象が発生してから調査担当者に依頼が届くまでに数日とか1週間とかの遅延が発生するケースもあります。発生日時を伝えずに何週間分ものログだけを送付されても、調査担当者は困ってしまいます。調査担当者としては、「昨夜、○○というプロセスが異常終了しました」のような説明ではなく「○月○日○時○分頃、○○というプロセスが異常終了しました」のような説明が欲しいのです。

strace コマンドにはいろいろなオプションがありますが、システムコールを発行した時刻を付与するための -tt というオプションと、システムコールの実行に要した時間を付与するための -T というオプションは必須とも言えるでしょう。

strace コマンドは、既に動作中のプロセスの挙動を追いかけることも、 strace コマンド実行時のコマンドラインから起動されるプロセスの挙動を追いかけることもできます。先に、既に動作中のプロセスの挙動を追いかける方法を説明します。

まず、プロセスの名前からプロセスIDを探すには pidof というコマンドを使用します。

# pidof 対象となるプロセスの名前

pidof コマンドが出力したプロセスIDを strace コマンドの -p オプションに渡します。 -p オプションを繰り返すことで複数のプロセスIDを指定できます。

# strace -tt -T -p 対象となるプロセスID1 -p 対象となるプロセスID2

もし、対象となるプロセスIDが1個だけであることが明らかであれば、 strace コマンド実行時のコマンドラインで pidof コマンドを実行することもできます。

# strace -tt -T -p `pidof 対象となるプロセスの名前`

マルチスレッドなプログラムあるいは当該プロセスが今後作成する子プロセスを含めて対象にしたい場合には、 -f というオプションも指定します。例えば rsyslogd はマルチスレッドで動作するので、 -f オプション付きで実行します。

# strace -tt -T -f -p `pidof rsyslogd`

上記のように実行することで挙動を追跡できるようになりますが、ログがすぐに画面上から消えてしまっては意味がありません。そのため、実際にはログファイルに保存するための -o オプションも付けることになるでしょう。

# strace -tt -T -f -o rsyslogd-strace.log -p `pidof rsyslogd`

strace コマンドを終了させるには、キーボードから Ctrl-C を入力します。対象となるプロセスIDを指定して strace コマンドを実行する方法であれば、 strace コマンドによる追跡だけを終了させることができますので、デーモンとして動作するプロセスを一時的に追跡する場合に重宝します。

次に、 strace コマンド実行時のコマンドラインから起動されるプロセスの挙動を追いかける例を示します。

$ strace -tt -T -f -o echo-strace.log /bin/echo 'Happy Holidays!'

strace コマンド実行時のコマンドラインから起動されたプロセスが終了すると strace コマンドも自動的に終了するので、デーモンではないプロセスを追跡する場合に重宝します。

strace コマンドは、カーネルとプログラムとの接点であるシステムコール呼び出しを追跡するため、カーネル側の問題か否かを切り分ける目的で使用することもあります。プログラム側のソースコードを確認する方法は前回紹介したとおりです。ここから先は当該プログラムの知識が必要になるので、サポート窓口に解析を依頼することになるかもしれません。

スムーズな対応のために、ご利用の環境で strace コマンドを使用した情報取得を行うことを許容できるかどうかを、問題事象に遭遇する前に確認しておいてください。

(半田哲夫)

コーヒーブレーク「誰もがゲストで誰もがキャスト」

先日久しぶりにディズニーランドに行ってきました。シンデレラ城をキャンバスとするプロジェクションマッピング、「ワンス・アポン・ア・タイム」は大変な人気です。私も参加者(ゲスト)の一人として堪能させてもらいましたが、職業柄イベントの裏側が気になります。この壮大なショーはどれくらいの期間をかけて準備され、どんなふうにテストやリハーサルが行われ、どれだけのスタッフ(キャスト)が配置されているのか、と。

オリエンタルランドのウェブページに「ディズニーの世界を演出するために、園内の建物から音楽にいたるまで、あらゆるものがテーマを持って設計され、非日常的な空間を創りだしています」という言葉があります。訪れる「ゲスト」に「冒険、歴史、ファンタジー、未来をテーマとした日常の生活には存在しないような憧れに彩られた世界を、人間の持つ五感すべてを使って楽しんで欲しい」、そのために重ねられたであろう努力と準備を想像し、胸が熱くなりました。

働くということは誰かを助けること、そう考えれば、ディズニーランドで働いていなくても、誰もがキャストであり同時にゲストです。年齢、あるいは事情により仕事を持っていない人もその存在は、必ず誰かに与えているものがあり、役割がある、私はそう思います。
この記事が公開されるのは、12月24日の予定です。聖なる夜に、一人一人お世話になった(なっている)ものや人のことを振り返ってみるのも悪くないでしょう。

Linus Torvalds という学生が、自分の書いたコードを公開しなければ Linux は存在していません。スティーブ・ジョブズがいなければ、あなたが記事を読んでいるスマートフォンはまだ存在していないかもしれません。もっと根源的な話として、私たち一人一人は、ひとつの細胞、受精卵としてこの世での存在が始まっています。どんな人もその両親がいなければ、存在していません(さらにその両親の両親も・・・)。
生きているということは、 DNA というバトンを引き継いでいるということです。途中の誰か一人がいなくても、あなたも私も存在していないのです。

誰しも、うまくいっていないこと、思うようにできていないこともあると思います(もちろん、私もそうです)。でも、自分なりに頑張ったのですから、自分にも声をかけてあげましょう、「一年間、よくやったね。頑張ったね」と。

本記事が 2014 年最後のコラムとなります。本コラムを書くことができること、読んでいただける方々がいることに感謝し、来年も一層有用な情報をご提供したいと思います。
では、また来年お会いしましょう(それまであなたのシステムとあなたとあなたの大切な人が平和でありますように!)。

(原田季栄)



第11回「 strace ノススメ」