RHEL6/7: 便利な trace-cmd および ftrace コマンド

この記事は、便利な trace-cmd および ftrace コマンドをまとめたものです。
遠慮せずに更新して新しいコマンドを追加してください。

重要な注意事項:

• RHEL6 は、trace-cmd バージョン 1.0.5 を使用します。
• RHEL7 は、trace-cmd バージョン 2.2.2 を使用します。

インストールするには:

yum install trace-cmd

オプションと引数は、RHEL のバージョンによって異なる場合があります。最新バージョンの trace-cmd にアップグレードできます。以下を参照してください。
https://git.kernel.org/cgit/linux/kernel/git/rostedt/trace-cmd.git/

アップストリームからアップグレードするには:

yum group install "Development Tools"
git clone git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/trace-cmd.git
cd trace-cmd
make
make install

ただし、上記のバージョンの Trace-cmd は Red Hat ではサポートされていないため、ケースを担当する Red Hat エンジニアの指示で追加機能が必要な場合にのみアップグレードする必要があります。サポートされているバージョンからほとんどの機能を利用できるため、デフォルトでそれらを使用してください。

Wakeup Tracer: タスクの実行準備が整ってから実行されるまでにかかる時間を確認します。

[root@localhost]# cd /sys/kernel/debug/tracing

echo wakeup > current_tracer
echo 0 > tracing_max_latency
echo 1 > events/enable
echo 1 > tracing_on && sleep 1 && echo 0 > tracing_on
cat trace 

Function Profiler : 各関数にかかる時間を調べます。

echo 0 > function_profile_enabled (clear previous profiler data)
echo 1 > function_profile_enabled
echo nop > current_tracer
echo *icmp* > set_ftrace_filter
echo 1 > tracing_on && ping -c 1000000 -i 0 127.0.0.1 > /dev/null && echo 0 > tracing_on
cat trace_stat/functionX (CPU Core)

IRQ レイテンシー: レイテンシーの高いものを見つけます

trace-cmd record -p function_graph -e irq_handler_entry -l do_IRQ sleep 10
trace-cmd report

出力サンプル

SpiderOakBlue-5699  [002] 20507.754014: irq_handler_entry:    irq=59 name=enp0s25
SpiderOakBlue-5699  [002] 20507.754019: funcgraph_exit:         4.330 us   |  }
gnome-shell-5405  [001] 20507.773000: funcgraph_entry:                   |  __irqentry_text_start() {
gnome-shell-5405  [001] 20507.773003: irq_handler_entry:    irq=62 name=i915
gnome-shell-5405  [001] 20507.773021: funcgraph_exit:       + 19.418 us  |  }

Soft IRQ を確認する: Soft IRQ が何を行っているか、どのくらいの時間がかかっているかを把握します。
RHEL7

trace-cmd record -p function_graph --profile -g do_softirq -e irq:softirq_entry sleep 10
trace-cmd report
trace-cmd report --profile

RHEL6

trace-cmd record -p function_graph -g do_softirq -e irq:softirq_entry sleep 10
trace-cmd report

出力サンプル

  Event: softirq_raise:TIMER (1) Total: 53150 Avg: 53150 Max: 53150(ts:20644.345014) Min:53150(ts:20644.345014)
| 
+ tick_sched_handle.isra.15 (0xffffffff810d5b45)
100% (1) time:53150 max:53150(ts:20644.344985) min:53150(ts:20644.344985) avg:53150
tick_sched_timer (0xffffffff810d5bc1)
__run_hrtimer (0xffffffff8109f637)
hrtimer_interrupt (0xffffffff8109fe77)
local_apic_timer_interrupt (0xffffffff810471c7)
smp_trace_apic_timer_interrupt (0xffffffff816316b6)
trace_apic_timer_interrupt (0xffffffff8162fd9d)
__schedule (0xffffffff81623ac8)
schedule (0xffffffff81624119)
worker_thread (0xffffffff81094279)
kthread (0xffffffff8109b68f)
ret_from_fork (0xffffffff8162f018)

場合によっては、CPU ごとの ftrace バッファーを増やす必要があります。これをテストして、ftrace バッファーがオーバーフローせず、情報が失われないことと、環境内のカーネルメモリー消費量との間の最適なバランスを見つける必要があります。-b を使用しますオプション。例えば:

# trace-cmd record -p function_graph -g do_softirq -e irq:softirq_entry -b 1048576 sleep 10

ユーザー空間タスクがカーネル空間で何を行っているかを確認します。タスク (またはその子) がそのタスクによって引き起こされるアクティビティーによって実行されるときに、カーネル空間で何が起こっているかを把握します。たとえば、一部のシステムコールで予期しない速度が低下する場合に役立ちます。Trace.dat の収集は root から実行する必要があります。

trace-cmd record -p function_graph -F -c <executable_command>

または sudo の下で:

[user@machine test]$ sudo trace-cmd record -p function_graph -F -c <executable_command>

Trace-cmd は、PID を使用してすでに実行中のプロセスに接続することもできます。

[user@machine test]$ sudo trace-cmd record -p function_graph -F -P <PID>

十分なデータが収集されたら、Ctrl-C を押して停止する必要があります。