本文の内容は、2014年12月16日にSysdigのCTO Loris Degionanniが投稿したブログ(https://sysdig.com/blog/interpreting-sysdig-output/)を元に日本語に翻訳・再構成した内容となっております
** 最も強力なシステムトラブルシューティングツールはすべて、共通の1つの特徴を持っている傾向があります。それは、無視できない学習曲線です。 格言にもあるように、レースカーを運転したい場合は、ドライブスティックを学ばなければなりません*。 公平を期すために、できる限り直感的で簡単に使用できるようにsysdigをゼロから設計しました。 ただし、ツールを最大限に活用するには、システムレベルの情報がsysdig出力でどのように表示されるかを理解しておくと間違いなく役立ちます。 この投稿では、オペレーティングシステムの基本的な要素をいくつか見ていき、sysdigでどのように表されるかを説明します。
- Processes と Threads
- File Descriptors
- Events, System Calls と Switches
Sysdig 出力の基本
フィルターなしでsysdigを実行すると、次のような出力が生成されます(説明を簡単にするために色を追加しました)。
1 01:40:19.601363716 1 httpd (7513) > accept
2 01:40:19.601374197 1 httpd (7513) < accept fd=14(127.0.0.1:39175->127.0.0.1:80) tuple=127.0.0.1:39175->127.0.0.1:80 queuepct=0
3 01:40:19.601506564 1 httpd (7513) > read fd=14(127.0.0.1:39175->127.0.0.1:80) size=8000
4 01:40:19.601512497 1 httpd (7513) < read res=85 data=GET /textfile.txt HTTP/1.1..User-Agent: curl/7.35.0..Host: 127.0.0.1..Accept: */
5 01:40:19.601516976 0 httpd (3750) > switch next=0 pgft_maj=0 pgft_min=522 vm_size=350196 vm_rss=9304 vm_swap=0
6 01:40:19.601661779 1 httpd (7513) > open
7 01:40:19.601668329 1 httpd (7513) < open fd=15(/opt/lampp/htdocs/textfile.txt) name=/opt/lampp/htdocs/textfile.txt flags=1(O_RDONLY) mode=0
8 01:40:19.601699335 1 httpd (7513) > read fd=14(127.0.0.1:39175->127.0.0.1:80) size=8000
9 01:40:19.601701560 1 httpd (7513) < read res=-11(EAGAIN) data=
10 01:40:19.601855764 1 httpd (7513) > close fd=15(/opt/lampp/htdocs/textfile.txt)
11 01:40:19.601857490 1 httpd (7513) < close res=0** **
sysdigによって出力されるフィールドは次のとおりです。
- Incremental event number
- Event timestamp – customize this with the -t command line flag (more info)
- CPU ID
- Command name
- Thread ID
- Event direction – ‘>’ means ‘enter’, while ‘<’ means ‘exit’
- Event type
- Event arguments
ここで、この出力をもう少し詳しく見てみましょう。ここでは、基本的なオペレーティングシステムの要素がsysdigによってどのように表されるかを確認します。
Processes と Threads
スレッドは、オペレーティングシステムのコア実行ユニットであり、結果としてsysdigでも同様です。複数のスレッドが同じプロセスまたはコマンド内に存在し、メモリなどのリソースを共有できます。 これは、上記のキャプチャスニペットに明確に示されています。スニペットのすべてのイベントはhttpdコマンドによって生成されますが、そのうちの1つ(番号5)は異なるCPUの異なるスレッドからのものです。
スレッドID(別名TID)は、マシンの実行アクティビティを追跡するときに追跡する基本的な識別子です。 これを行うには、TID番号を確認するか、次のようなコマンドラインでノイズを除去します。
> sysdig thread.tid=7513
これにより、スレッド7513の実行フローのみが保持されます。
スレッドはプロセス内に存在し、プロセスID(またはPID)によって識別されます。 平均的なLinuxボックスで実行されているプロセスのほとんどはシングルスレッドであり、その場合、thread.tidはproc.pidと同じです。 proc.pidによるフィルタリングは、プロセス内で異なるスレッドが互いにどのように相互作用するかを観察するのに役立ちます。
また、いくつかの小さなトリックがあります。シングルスレッドプロセスのイベントのみを表示する場合は、次のコマンドラインを使用できます。
> sysdig proc.nchilds=0
特定のユーザーセッションまたはスクリプトをトレースする場合は、以下のように使用できます。
> sysdig proc.apid = X
…Xはスクリプトを実行しているシェルのpidです
File Descriptors
上記のイベントのいくつかには「fd」と呼ばれる引数があることに気づいたかもしれません。
スレッドIDが実行のフローを識別する場合、ファイル記述子(FD)は入出力フローを識別します。
UNIXでは、次のような多くのものがファイルとして抽象化されます。
- files
- network connections (sockets)
- standard input, standard output, and standard error
- pipes
- timers
- signals
FDは、プロセス内のファイルを一意に識別する数値IDです。 これは、同じFD番号が複数回使用されていることを確認できますが、異なるプロセスにある必要があることを意味します。 プロセス/ FDの組み合わせに従うことにより、特定のI/Oアクティビティを追跡でき、通常どおりフィルターを使用して次のことができます。
> sysdig proc.name=httpd and fd.num=14
Sysdigは、FD番号を人間が読める文字列に変換することに対しても十分に優れています。 たとえば、上記のスニペットでは、FD 14が127.0.0.1:39175->127.0.0.1:80としてどのように表されているかに注目してください。
- これは IPv4 socket (4)です
- ソケットL4 プロトコルは、TCP(t)です
- 接続は127.0.0.1のポート39175によって確立されました
- 接続の宛先は、127.0.0.1のポート80です。
この情報はすべて、フィルタにおいて便利に使用でき、興味深いアクティビティを分離できます。 例えば:
> sysdig fd.type=ipv4
> sysdig fd.l4proto=tcp
> sysdig fd.sip=127.0.0.1
> sysdig fd.sport=39157
Events
sysdigがキャプチャおよび表示するイベントのほとんどはシステムコールです。 システムコールインターフェイスには、オペレーティングシステムがその上で実行されているアプリケーションにエクスポートして、開いているファイルなどの処理、ネットワーク接続の作成、FDからの読み取りおよび書き込みなどを行う多数の「機能」が含まれます。
通常、次のように入力すると、sysdigイベントの1つに関する詳細情報を取得できます。
> man 2 <event_name>
ターミナルまたはグーグルで。 ただし、straceのようなツールとは異なり、sysdigはシステムコールの構文を絶対精度でミラー化しないことに注意してください。**これは、たとえシステムコールのマニュアルページから、 イベントが行うこととその引数の意味は、元のシステムコールと対応するsysdigイベントの間に矛盾がある可能性があります。 イベントの引数が何かを知りたい場合は、次のように入力します。
> sysdig -L
このコマンドを実行するとわかるように、sysdigは多くのイベントをエクスポートします。 ただし、それらのいくつかは、デバッグや調査に役立つ傾向があります。 例えば:
- clone()およびexecve()は、プロセスの作成とコマンドの実行に関する洞察を提供します。
- open()、close()、およびFDの読み取りおよび書き込み関数は、ディスクI/Oの可視性を提供します。
- socket()、connect()、およびaccept()は、ネットワークアクティビティに関する洞察を提供します。
これらのシステムコールが何をするのか、そしてそれらをどのように解釈するのかに興味があるなら、こちらの「魅力的なLinuxシステムコールの世界」をご覧ください。
Switch Event
sysdigがシステムコールのキャプチャに限定されないことに気付かない人もいます。Sysdigはカーネルを利用して、他の種類のイベントも報告します。 たとえば、スイッチイベントは、コンテキスト切り替えがあるたびに、つまりプロセススケジューラがスレッドをスリープ状態にして別のスレッドを実行するたびに生成されます。 スケジューラアクティビティの監視は、プロセス/スレッドが高い粒度で実行されるタイミングの決定、プロセス同期の問題のデバッグ、スレッドが別のCPUに移行されるタイミングの監視などのシナリオに役立ちます。
スイッチはシステムコールではないため、マニュアルページはありません。 また、exitイベントを持たない数少ないsysdigイベントの1つであるため、方向としてはenterのみが表示されます。 また、sysdigは、アクティビティが比較的少ないシステムでも多くの場合、スイッチをプリントすることがあるため、スイッチは時々うっとうしい時があります。幸いなことに、不要な場合は簡単に除外できます。
> sysdig evt.type!=switch
まとめ
プロセス、スレッド、ファイル記述子、システムコール、およびコンテキストスイッチは、Linuxオペレーティングシステムの基本的な要素の一部です。 sysdigがこれらの要素に関する情報をどのように表すか、およびsysdigを使用してシステムを非常に強力な方法で探索する方法がより明確になれば幸いです。 ;)sysdigの詳細については、wikiのsysdigユーザーガイドをご覧ください。
画面に表示されるすべてのsysdig出力が何を意味するのか理解できたので、次に、監視するシステムコールとそれらが隠す有用な情報は、こちらの「魅力的なLinuxシステムコールの世界」をご覧ください。
**これはそれ自体が格言ではないかもしれませんが、私の友人であるジェラルド・コームズはただそれを言いました…それで今は格言だと思います。 ありがとうジェラルド! :)*
***ご参考までに、これの主な理由はパフォーマンスです。 sysdigの主な設計目標は効率性であるため、最小限のオーバーヘッドで本番環境で使用できます。 これにより、ページフォールトの確率を最小限に抑えるために、引数が返される順序に制約が設定されます。 さらに、sysdigはいくつかのシステムコールにいくつかの便利な引数を追加します。 たとえば、brkやmmapなどのメモリ関連のイベントは、プロセスの合計メモリ使用量を返します。これは、メモリ関連の問題のトラブルシューティングを行うときに便利です。 *