本文書に関する指摘については、原文著者のTanel Poderさんではなく、渡部まで御連絡お願いいたします。
注意事項
- 自動翻訳に手を加えたレベルの翻訳と理解してください
- 意味をとりやすくするために追加した箇所については、《…》で囲っています。
- 訳がわからない、または、自信がない箇所は★をつけています。
日本語訳:渡部 亮太 (WR at Csus4 dot net)
履歴
- 2013-04-09: 初稿up
quick'n'dirtyトラブルシューティングのために/procファイルシステムを使用してLinuxカーネルランドを覗く
このブログは、モダンなLinuxについてのものです。言い換えれば、2.6.3xのカーネル相当のRHEL6についてであり、、残念ながら企業の中で最も一般的である2.6.18カーネル相当の古代のRHEL5(なにこれ?!)についてではありません。そして、いや、私は、カーネルデバッガまたはSystemTapスクリプトを使用するつもりはありません。昔ながらの "cat /proc/PID/xyz"のコマンドを、いくつかの有用な/ procファイルシステムのエントリに対して使います。
"遅い"プロセスのトラブルシューティング
これは、私のラップトップで再現させた1つの体系的なトラブルシューティングの例です。彼らが実行したfindコマンドはしばらくの間何も結果を返さずに、"かなり遅く"実行されていたことを、DBAは不思議に思っていた。環境を知って、我々は《原因を》直感したが、私はこれ -のたった今 – すでに進行中の問題 – に対するトラブルシューティングの体系的なアプローチがどのようなものかについて尋ねられてしまった
幸いにもシステムではOEL6を実行していたので、かなり新しいカーネルだった。実際には、2.6.39 UEK2であった。
では、いくつかトラブルシューティングを行ってみましょう。まず最初に、そのfindプロセスがまだ生きているかどうかを見てみましょう:
[root@oel6 ~]# ps -ef | grep find
root ? ? 27288 27245 ?4 11:57 pts/0 ? ?00:00:01 find . -type f
root ? ? 27334 27315 ?0 11:57 pts/1 ? ?00:00:00 grep find
うん、生きています。 – PIDは27288です。(トラブルシューティングの例では、そのpidを使用します)。
基礎から始めて、このプロセスのボトルネックが何であるかを簡単に見てみましょう。によってそれが何かに(それがキャッシュから必要なものをすべて読んなど)ブロックされていない場合、CPUを100%使用しているでしょう。 もし、いくつかのIOや競合の問題がボトルネックであるならば、 CPU使用率は低いか、または完全に0%でなければならない。
[root@oel6 ~]# top -cbp 27288
top - 11:58:15 up 7 days, 3:38, 2 users, load average: 1.21, 0.65, 0.47
Tasks: 1 total, 0 running, 1 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.1%us, 0.1%sy, 0.0%ni, 99.8%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 2026460k total, 1935780k used, 90680k free, 64416k buffers
Swap: 4128764k total, 251004k used, 3877760k free, 662280k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
27288 root 20 0 109m 1160 844 D 0.0 0.1 0:01.11 find . -type f
topコマンドは、このプロセスはCPUの使用率が0%であるか、また??はゼロパーセントに非常に近い(それが出力に0%に丸められます)ことを示しています。全くCPUを使用するチャンスがない完全にstuckしたプロセスと、時々待機状態から抜け出すプロセス(例えば、いくつかのポーリング操作が時々タイムアウトして、スリープ状態に戻ることを選択する) については、重要な違いがある。だから、Linux上のtopコマンドは確かにその違いを示すために十分なツールではありません – しかし、少なくとも我々は、このプロセスが多くのCPU時間のを使っていないことを知っています。
その後、何か他のものを使用しましょう??。通常、プロセスがそのようにstuckしているように見えるとき、プロセスが現在stuckしているシステムコールにトレースするために、私はstrace
コマンドを実行します。
(CPU使用率0%は通常、プロセスが何らかのブロッキングシステムコールでスタックしていることを意味します- これは、カーネルがプロセスをsleepさせることになります)
プロセスは、実際に完全にstuckしておらず、システムコールから戻り、ときどき目を覚ますならば、それがstraceで現れるでしょう(ブロッキングシステムコールが完了し、少し後に再度システムコールを実行するような):
[root@oel6 ~]# strace -cp 27288
Process 27288 attached - interrupt to quit
^C
^Z
[1]+ Stopped strace -cp 27288
[root@oel6 ~]# kill -9 %%
[1]+ Stopped strace -cp 27288
[root@oel6 ~]#
[1]+ Killed strace -cp 27288
おっと、straceコマンドもhungしました! 長い時間は出力を表示しませんでしたし、Ctrl + Cキーに応答しなかったので、私はCtrl + Zでバックグラウンドにして、そこからそれをkillしなければならなかった。So much for easy diagnosis.★
では、pstackを試してみましょう(Linuxでは、pstackはただのGDB
デバッガのシェルスクリプトラッパーです)。pstackはカーネルランドを見ないが、私達に、システムコールが要求されたか箇所についての手掛かりを与える:(通常、ユーザランド?スタックのトップに、対応するlibcライブラリコールがあるので)
[root@oel6 ~]# pstack 27288
^C
^Z
[1]+ Stopped pstack 27288
[root@oel6 ~]# kill %%
[1]+ Stopped pstack 27288
[root@oel6 ~]#
[1]+ Terminated pstack 27288
pstackも、何も返さずにstuckしてしまった!
だから、我々はまだ、我々のプロセスが100%(絶望的)stuckなのか、または単に99.99%stuckなのか(プロセスはスリープ状態に戻ることを続けているのか)をしりません。stuckしている箇所も知りません。
OK、他にどこを見れば?一般的に入手可能でチェックすべきものが1つ以上あります – 古き良きpsコマンドを経由してレポートできる、プロセスの状態とWCHANフィールド:
(このプロセスがゾンビではないことを確認するために、私はもっと早くこのコマンド実行しておくべきだったかもしれない)
[root@oel6 ~]# ps -flp 27288
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
0 D root 27288 27245 0 80 0 - 28070 rpc_wa 11:57 pts/0 00:00:01 find . -type f
プロセスが同じ状態のままであることを確認するために、あなたは、in a row、psを複数回実行する必要があります(あなたが不運な時に取得した、1つのサンプルに惑わされたくはありません)が、私は簡単のため一度だけそれをここに表示しています。
プロセスは、(psのmanページも言うように)通常ディスクIO関連である状態D(割り込み不可のスリープ)になっています。そして、WCHAN(このプロセスでのスリープ/待機を引き起こした関数)フィールドは少し切り捨てられています。少し広くこれをプリントアウトするには、(manを読んで)psオプションを使うことができますが、この情報は結局のところprocファイルシステムから来ているので、ソースから直接それを問い合せることにします。(繰り返しになるが、プロセスが完全にstuckしているか、または単にほとんど寝ているかどうかはまだわからないので、複数回サンプリングをすると良いだろう):
[root@oel6 ~]# cat /proc/27288/wchan
rpc_wait_bit_killable
うーん…このプロセスは、いくつかのRPCコールを待っています。RPCは、通常、プロセスが他のプロセス(ローカルサーバーまたはリモートサーバーであっても)と話していることを意味します。しかし、我々はまだ理由がわからない。
なにか動きがあるか、またはプロセスが完全にstuckしているか?
この資料の "meat"に進む前に、このプロセスが完全にstuckしているかどうかを把握しましょう??。モダンなカーネルでは、/proc/PID/statusがこれを私たちに教えることができる。私は、我々の目的のための興味深いところを強調している:
[root@oel6 ~]# cat /proc/27288/status Name: find State: D (disk sleep)
Tgid: 27288 Pid: 27288 PPid: 27245 TracerPid: 0 Uid: 0 0 0 0 Gid: 0 0 0 0 FDSize: 256 Groups: 0 1 2 3 4 6 10 VmPeak: 112628 kB VmSize: 112280 kB VmLck: 0 kB VmHWM: 1508 kB VmRSS: 1160 kB VmData: 260 kB VmStk: 136 kB VmExe: 224 kB VmLib: 2468 kB VmPTE: 88 kB VmSwap: 0 kB Threads: 1 SigQ: 4/15831 SigPnd: 0000000000040000 ShdPnd: 0000000000000000 SigBlk: 0000000000000000 SigIgn: 0000000000000000 SigCgt: 0000000180000000 CapInh: 0000000000000000 CapPrm: ffffffffffffffff CapEff: ffffffffffffffff CapBnd: ffffffffffffffff Cpus_allowed: ffffffff,ffffffff Cpus_allowed_list: 0-63 Mems_allowed: 00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001 Mems_allowed_list: 0 voluntary_ctxt_switches: 9950 nonvoluntary_ctxt_switches: 17104
プロセスは状態D?-ディスク スリープ(割り込み不可のスリープ) – にある。そして、voluntary_ctxt_switches
とnonvoluntary_ctxt_switches
の数を見てみる – これは、プロセスがCPUを取り上げられた(または戻した)回数を示します。そして、数秒後にもう一度同じコマンドを実行し、それらの数値が増加したかどうかを見てください。私のケースでは、これらの数字は増加しなかった。よって、私は、(まあ、少なくとも数秒の間にこれらのコマンドの間は)プロセスが完全にstuckしていたと結論付けることができた。だから、私は、このプロセスは完全にstuckしていると今ではもっと自信を持つことができます。(そして、ずっとCPU時間の0.04%を使って、レーダーの下を飛んでいる《0%とみなされるぐらい小さい値のことを指しているのでは》のではないことも)
ところで、コンテキストスイッチの数を取得できる場所は、2つ以上あります。(そして、2番目の場所が古代のカーネルでも同様に機能します)
[root@oel6 ~]# cat /proc/27288/sched find (27288, #threads: 1) \--------------------------------------------------------- se.exec_start : 617547410.689282 se.vruntime : 2471987.542895 se.sum_exec_runtime : 1119.480311 se.statistics.wait_start : 0.000000 se.statistics.sleep_start : 0.000000 se.statistics.block_start : 617547410.689282 se.statistics.sleep_max : 0.089192 se.statistics.block_max : 60082.951331 se.statistics.exec_max : 1.110465 se.statistics.slice_max : 0.334211 se.statistics.wait_max : 0.812834 se.statistics.wait_sum : 724.745506 se.statistics.wait_count : 27211 se.statistics.iowait_sum : 0.000000 se.statistics.iowait_count : 0 se.nr_migrations : 312 se.statistics.nr_migrations_cold : 0 se.statistics.nr_failed_migrations_affine: 0 se.statistics.nr_failed_migrations_running: 96 se.statistics.nr_failed_migrations_hot: 1794 se.statistics.nr_forced_migrations : 150 se.statistics.nr_wakeups : 18507
se.statistics.nr_wakeups_sync : 1 se.statistics.nr_wakeups_migrate : 155 se.statistics.nr_wakeups_local : 18504 se.statistics.nr_wakeups_remote : 3 se.statistics.nr_wakeups_affine : 155 se.statistics.nr_wakeups_affine_attempts: 158 se.statistics.nr_wakeups_passive : 0 se.statistics.nr_wakeups_idle : 0 avg_atom : 0.041379 avg_per_cpu : 3.588077 nr_switches : 27054 nr_voluntary_switches : 9950 nr_involuntary_switches : 17104
se.load.weight : 1024 policy : 0 prio : 120 clock-delta : 72
ここでは、nr_switches
の数(nr_voluntary_switches
+ nr_involuntary_switches
に等しい)を調べる必要があります。
nr_switchesの合計は上記の出力では27054であり、これは、/proc/PID/schedstatショーの3番目のフィールドでも表示されます:
[root@oel6 ~]# cat /proc/27288/schedstat
1119480311 724745506 27054
そして、それは増加していませんでした…
/procファイルシステムを使用して、カーネルランドを覗く
だから、それは私たちのプロセスはかなりstuckしているように見えます straceとpstackは役に立たなかった。それらのコマンドは、プロセスにアタッチして、そのメモリを覗くために、ptrace()システムコールを使用しますが、非常に可能性が高いいくつかのシステムコールで、プロセスが絶望的にstuckしていると、ptrace()コールもhungするのだと私は推測しています。(ところで、ターゲットプロセスにアタッチするとき、straceのプロセス自体をstracingしようとしたことがある。すると、それはターゲットをクラッシュさせた。あなたに警告しましたよ
それで、どのシステムコールでstuckしているかを確認する方法は? – straceやpstackなしで幸いにも私は最新のカーネルで実行されていた – /proc/PID/syscall に挨拶しましょう★!
[root@oel6 ~]# cat /proc/27288/syscall
262 0xffffffffffffff9c 0x20cf6c8 0x7fff97c52710 0x100 0x100 0x676e776f645f616d 0x7fff97c52658 0x390e2da8ea
OK WTF 私はそれをどうするんだって?
さて、これらの数字は、通常何かを示している。それは "0xある大きな数"の場合、それは通常、メモリアドレス(およびそれらが指す場所のpmapのようなツールを使用することができる)ですが、それが小さな数の場合、おそらくそれは、いくつかの配列のインデックスだ – (/proc/PID/fd
から読むことができるような)オープンされたファイル記述子の配列 または、今回の場合は、我々はシステムコールを扱っている、- それはあなたのプロセスが現在いる、システムコール番号です!だから、このプロセスは、システムコール#262でstuckしている!
システムコール番号は、OSの種類、OSのバージョン、プラットフォーム間で異なる可能性があることに注意してください。OSの種類に応じて適切なヘッダファイル(*.h)からそれを読むべきです。通常は/usr/includeから "syscall*"を検索することが、良いスタートポイントです。Linuxの私のバージョンとプラットフォーム(64ビット)上のシステムコールは、/usr/include/asm/unistd_64.h
のここで定義されています:
[root@oel6 ~]# grep 262 /usr/include/asm/unistd_64.h
#define __NR_newfstatat 262
お待たせしました!syscall 262 はnewfstatat
と呼ばれるものでした。それが何であるかを調べるために、単に manを実行します。ここでは、システムコールの名前に関するヒントがあります – manページが呼び出しを見つけることができなかった場合、次に可能な接尾辞と接頭辞なしでをmanを実行してみてほしい (たとえば、代わりに "man pread64"の "man pread") – この場合は、"new"という接頭辞なしで man fstatat
。さもなくばgoogleを。
とにかく、このシステムコール"new-fstat-at"は、あなたは、通常のstat
システムコールのように、ファイルのプロパティを読み取ることができます。そして、我々は、このファイルのメタデータの読み取り動作でstuckしている。だから、我々はさらに一歩進んだことになるしかし、なぜそこでstuckしているかが我々はまだ分からない。
さて、 /proc/PID/stackにSay Hello To My Little Friendしてみよう。これは、単位procファイルをcatするだけで、プロセスのカーネルスタックのバックトレースを読み取ることができる!
[root@oel6 ~]# cat /proc/27288/stack
[] rpc_wait_bit_killable+0x24/0x40 [sunrpc]
[] __rpc_execute+0xf5/0x1d0 [sunrpc]
[] rpc_execute+0x43/0x50 [sunrpc]
[] rpc_run_task+0x75/0x90 [sunrpc]
[] rpc_call_sync+0x42/0x70 [sunrpc]
[] nfs3_rpc_wrapper.clone.0+0x35/0x80 [nfs]
[] nfs3_proc_getattr+0x47/0x90 [nfs]
[] __nfs_revalidate_inode+0xcc/0x1f0 [nfs]
[] nfs_revalidate_inode+0x36/0x60 [nfs]
[] nfs_getattr+0x5f/0x110 [nfs]
[] vfs_getattr+0x4e/0x80
[] vfs_fstatat+0x70/0x90
[] sys_newfstatat+0x24/0x50
[] system_call_fastpath+0x16/0x1b
[] 0xffffffffffffffff
最上位の関数が、私たちが今stuckしている箇所のカーネルコードである – それは、正確にWCHAN 出力が見せてくれたものになっている。(実際には、その上にいくつかのより多くの関数があることに注意してほしい。たとえば、プロセスをスリープさせたり、必要に応じてCPUを割り当てたりするカーネルのschedule()
関数のように。しかし、それらは、おそらくここには示されない。なぜならば、原因ではなくて、待ち条件の結果であるからだ。)
このタスクの完全なカーネルランド?スタックのおかげで、どのようにして、このrpc_wait_bit_killable
関数を呼ぶことになったのかを理解するために、ボトムアップからそれを読むことができます。そして、スケジューラを呼び出して、スリープモードに私たちを入れてしまうことになったのかを。
ボトムのsystem_call_fastpath
は、我々が発行したnewfstatatシステムコール(sys_newfstatat
)のための、カーネルコードを呼び出した汎用のカーネル システムコールハンドラ関数です。そして、 "子"の関数を通って上方に行き続けて、我々は、スタックのNFS機能の束に会うことになる!これは、我々は、NFSコードパスの下のどこかであることを100パーセント否定できない証拠です★。私は "NFSのコードパスの中"とは言わない。 あなたがNFS関数を超えて上向きに読み続けたとき、あなたは一番上のNFS関数は、他のプロセス – このケースは、おそらく、[kworker/N:N]
[nfsiod]
[lockd]
または[rpciod]
カーネルIOスレッド – に通信するためのいくつかのRPC機能(rpc_call_sync)をコールしているのを見る。そして、我々はいくつかの理由で(たいていの疑いは、ネットワーク接続、パケットまたは単にネットワーク接続の問題を落としたであろう)のために、それらのスレッドからの応答を取得することがない。
ヘルパースレッドのいずれかがネットワーク関連のコードに引っかかっているかどうかを確認するためには、それらのカーネルスタックをサンプリングできます。しかし、kworkersは単なるNFS RPC通信より多くのことを行う。別の実験(ちょうど、NFS経由で大きなファイルをコピーする)の間に、あるkworkersがネットワークコードで待機していることをキャッチした:
[root@oel6 proc]# for i in `pgrep worker` ; do ps -fp $i ; cat /proc/$i/stack ; done UID PID PPID C STIME TTY TIME CMD root 53 2 0 Feb14 ? 00:04:34 [kworker/1:1] [] __cond_resched+0x2a/0x40 [] lock_sock_nested+0x35/0x70 [] tcp_sendmsg+0x29/0xbe0 [] inet_sendmsg+0x48/0xb0 [] sock_sendmsg+0xef/0x120 [] kernel_sendmsg+0x41/0x60 [] xs_send_kvec+0x8e/0xa0 [sunrpc] [] xs_sendpages+0x173/0x220 [sunrpc] [] xs_tcp_send_request+0x5d/0x160 [sunrpc] [] xprt_transmit+0x83/0x2e0 [sunrpc] [] call_transmit+0xa8/0x130 [sunrpc] [] __rpc_execute+0x66/0x1d0 [sunrpc] [] rpc_async_schedule+0x15/0x20 [sunrpc]
[] process_one_work+0x13e/0x460 [] worker_thread+0x17c/0x3b0 [] kthread+0x96/0xa0 [] kernel_thread_helper+0x4/0x10
これは、カーネルが正確なカーネルスレッドは、他のカーネルスレッドと通信するための知っているのトレースを有効にすることが可能でなければなりませんが★、私はこの記事でそこに行くことはありません – 実用的な(そして単純な:)トラブルシューティングの練習であることになっている!
診断と "修正"
とにかく、最近のLinuxカーネルでは(それが導入されたとき、私は正確なバージョンがわからない)、非常に簡単なカーネルスタックのサンプリングのおかげで、我々は、findコマンドがstuckした箇所 – LinuxカーネルのNFSコードの中 – を体系的に把握することができました そして、NFS関連がハングアップしているときに、もっとよく疑われるのは、ネットワークの問題である。私がこの問題をどうやって再現できたか、貴方が疑問に思っているなら、私はVMからNFSボリュームをマウントしました。findコマンドを開始して、次にVMを単にsuspendしました。これは、TCPエンドポイントに通知することなく接続が暗黙的に削除されたか、パケットが何らかの理由で通らないようなネットワーク(構成、ファイアウォール)の問題と同様の症状を生成します。
スタックに記載されている最上位の関数が"killable"safe-to-kill関数(rpc_wait_bit_killable
)の1つであるため、その後私たちはkill -9
でそれを殺すことができる:
[root@oel6 ~]# ps -fp 27288
UID PID PPID C STIME TTY TIME CMD
root 27288 27245 0 11:57 pts/0 00:00:01 find . -type f
[root@oel6 ~]# kill -9 27288
[root@oel6 ~]# ls -l /proc/27288/stack
ls: cannot access /proc/27288/stack: No such file or directory
[root@oel6 ~]# ps -fp 27288
UID PID PPID C STIME TTY TIME CMD
[root@oel6 ~]#
プロセスがなくなっています。
Poor-manのカーネルスレッドプロファイリング
/proc/PID/stackはただのプレーンなテキストprocファイルのように見えるので、あなたはカーネルスレッドでもPoor-manのスタックプロファイリングを行うことができることに注意してください!これは、現在のシステムコールとカーネルスタック(システムコールの場合)をサンプリングし、それを貧乏人の方法で半階層的プロファイルに集約する例です。
[root@oel6 ~]# export LC_ALL=C ; for i in {1..100} ; do cat /proc/29797/syscall | awk '{ print $1 }' ; cat /proc/29797/stack | /home/oracle/os_explain -k ; usleep 100000 ; done | sort -r | uniq -c
69 running
1 ffffff81534c83
2 ffffff81534820
6 247
25 180
100 0xffffffffffffffff
1 thread_group_cputime
27 sysenter_dispatch
3 ia32_sysret
1 task_sched_runtime
27 sys32_pread
1 compat_sys_io_submit
2 compat_sys_io_getevents
27 sys_pread64
2 sys_io_getevents
1 do_io_submit
27 vfs_read
2 read_events
1 io_submit_one
27 do_sync_read
1 aio_run_iocb
27 generic_file_aio_read
1 aio_rw_vect_retry
27 generic_file_read_iter
1 generic_file_aio_read
27 mapping_direct_IO
1 generic_file_read_iter
27 blkdev_direct_IO
27 __blockdev_direct_IO
27 do_blockdev_direct_IO
27 dio_post_submission
27 dio_await_completion
6 blk_flush_plug_list
これは、あなたのカーネルでは、プロセスが時間を費やした箇所への非常に大まかなサンプルを与える – すべての場合。システムコール番号は上記に太字で分離されている – "running"は、このプロセスがサンプル中に(システムコール内ではなく)ユーザランドにいたことを意味します。だから、サンプリング中の時間の69%で、このプロセスはユーザランドのコードを実行していた。時間の25%は、システムコール #180(私のシステムでnfsservctl)で、6%がsyscall#247(waitid)。
この出力に見られるように、さらに2つの "関数"がある – しかし、何らかの理由でそれらが適切に関数名に翻訳されていません。さて、このアドレスが何かを表しています。手動での我々の運を試してみましょう:
[root@oel6 ~]# cat /proc/kallsyms | grep -i ffffff81534c83
ffffffff81534c83 t ia32_sysret
だから、これらのサンプルは32ビットアーキテクチャと互換性のあるシステムコールのリターン関数に関するものであることに見える – しかし、この関数はシステムコールではありません(単に内部ヘルパー関数)、おそらくそれが、/proc/stackのルーチンがそれを翻訳しなかった理由です。もしかすると、/procビューに"読取り一貫性"がないために、これらのアドレスが表示されたのかもしれない。所有するスレッドがこれらのメモリー構造とエントリを変更するとき、読み出しスレッドは、時には "in-flux"のデータを読むかもしれない。
他のアドレスも確認してみましょう:
[root@oel6 ~]# cat /proc/kallsyms | grep -i ffffff81534820
[root@oel6 ~]#
存在しない?まあ、トラブルシューティングをまだやめる必要はありません – そのアドレスの周りに何か面白いものがないか見てみましょう。アドレスから、trailingいくつかの文字を削除してみました:
[root@oel6 ~]# cat /proc/kallsyms | grep -i ffffff815348 ffffffff8153480d t sysenter_do_call ffffffff81534819 t sysenter_dispatch
ffffffff81534847 t sysexit_from_sys_call ffffffff8153487a t sysenter_auditsys ffffffff815348b9 t sysexit_audit
sysenter_dispatch関数は、/proc/PID/stackによって表示されたオリジナルのアドレスのわずか1バイト前にて、開始するように見えます。だから我々はおそらくすでに1バイト(おそらく動的トレースプローブトラップのためにそこに残されたNOP動作)を実行した。しかしそれにもかかわらず、これらのスタックのサンプルはsysenter_dispatch
関数の中にいるようにみえる。それは、システムコールではなく、システムコールヘルパー関数である。
スタックプロファイラの詳細
スタックサンプラーには様々な種類があることに注意してください- LinuxのPerf、oprofileツール、Solaris DTraceのprofile
プロバイダーは、CPUで現在実行中のスレッドの命令ポインタ(x64上の32ビットIntelまたはRIPのEIP) とスタック?ポインタ(64ビットで32ビットおよびRSP上のESP)のレジスタを実際にサンプリングします。そして、そこから逆方向にスタックポインタを歩く。したがって、これらのツールは、サンプリングしたときにCPUにいたスレッドのみを表示します!高CPU使用率の問題のトラブルシューティングのときひは、これはもちろん完璧です。しかし、hungしたプロセスやプロセスの非常に長いスリープと待機のトラブルシューティングには有用ではありません。
Linux、Solaris、HP-UXのpstack、(AIXの)procstack、ORADEBUG SHORT_STACKのようなツール、単に/proc/PID/stack 擬似ファイルを読むことは、CPUプロファイリングツールの良い追加(置き換えではなく)を提供する。
それらは、CPUスケジューリング状態に関係なく検出されたプロセスのメモリにアクセスし、そこからスタックを読むからだ。プロセスにCPUが割り当てられておらず、スリープしている場合は、スタックの開始点がストアドコンテキスト – コンテキストスイッチ中に、OSのスケジューラによってカーネル?メモリーに保存される – から読み取ることができます。
もちろん、CPUイベントプロファイリングツールは、しばしば単なるpstack、OProfile、Perfよりもはるかに多くの処理を行うことができる。(Solaris11の)DTraceのCPCプロバイダは、メインメモリを待ってストールしているCPUサイクルの量、L1/L2キャッシュミスの量等を推定するためのCPU内部のパフォーマンスカウンタを設定し、サンプリングできる。
Kevin Clossonがこれらのトピックについて言ったことを読んでみてほしい:(PERF 、 oprofile )
Enjoy