ftraceの解説と最近の動向 @第8回カーネル/VM探検隊 (株)日立製作所 横浜研究所 豊岡 拓 <[email protected]> Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved Agenda • ftraceとは • 使い方 • 最近の動向 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 2 トレースとは • 「プログラミングにおいて、命令の実行された形跡をた どること」 – 出典: http://ja.wikipedia.org/wiki/トレース • この発表で言うトレースは、プログラムの実行を理解 する上で有益なデータをバッファ等に記録すること 実行パス トレースポイント ／イベント トレースバッファ Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 3 トレースの用途 • デバッグ • 障害解析 • 性能解析 – ボトルネック解析 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 4 ftrace • Linuxカーネルに組込まれているトレース機構 – 元々はRTツリーのFunction tracerから始まった – メンテナ: Steven Rostedt氏 • 今では色んなトレース機能が統合されている – Events (tracepoints) – Latency (irq, preempt, wakeup) – Stack – Block, mmio – Dynamic events (Kprobes, Uprobes) Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 5 Trace Events • あらかじめ埋め込まれたトレースポイントを 踏んだ時にイベントを記録 syscall, sched, kmem, irq, fs, kvm, trace etc... point gnome-panel-1716 trace-cmd-3844 trace-cmd-3844 ome-panel-1716 ls-3845 ls-3845 ls-3845 gration/3-17 ...... [001] [002] [002] [001] [003] [003] [003] [003] 970.096184: 970.096185: 970.096188: 970.096188: 970.096192: 970.096193: 970.096194: 970.096196: event handler sched_stat_runtime: sched_stat_runtime: sched_switch: sched_switch: sched_wakeup: sched_stat_runtime: sched_switch: sched_stat_wait: trace buffer comm=gnome-panel pid=1716 runtime=31888 comm=trace-cmd pid=3844 runtime=230692 trace-cmd:3844 S ==> swapper/2:0 gnome-panel:1716 S ==> swapper/1:0 migration/3:17 [0] success=1 CPU:003 comm=trace-cmd pid=3845 runtime=93127 trace-cmd:3845 R ==> migration/3:17 comm=trace-cmd pid=3845 delay=4131 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 6 Trace Events • あらかじめ埋め込まれたトレースポイントを 踏んだ時にイベントを記録 プロセス名-PID タイムスタンプ CPU番号 gnome-panel-1716 trace-cmd-3844 trace-cmd-3844 ome-panel-1716 ls-3845 ls-3845 ls-3845 gration/3-17 ...... [001] [002] [002] [001] [003] [003] [003] [003] 970.096184: 970.096185: 970.096188: 970.096188: 970.096192: 970.096193: 970.096194: 970.096196: イベント名 sched_stat_runtime: sched_stat_runtime: sched_switch: sched_switch: sched_wakeup: sched_stat_runtime: sched_switch: sched_stat_wait: イベントごとの 引数 comm=gnome-panel pid=1716 runtime=31888 comm=trace-cmd pid=3844 runtime=230692 trace-cmd:3844 S ==> swapper/2:0 gnome-panel:1716 S ==> swapper/1:0 migration/3:17 [0] success=1 CPU:003 comm=trace-cmd pid=3845 runtime=93127 trace-cmd:3845 R ==> migration/3:17 comm=trace-cmd pid=3845 delay=4131 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 7 Trace Events • Kernelshark Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 8 “Function” Tracer • カーネル内の関数呼び出し／リターンを記録 – コールグラフ、処理時間が分かる ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_exit: ls-75 funcgraph_exit: ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_entry: ls-75 funcgraph_exit: ls-75 funcgraph_exit: ls-75 funcgraph_exit: ...... call～retの時間 0.054 0.446 0.883 0.055 0.057 0.056 1.291 1.732 3.402 | path_put() { | dput() { | _raw_spin_lock() { us| do_raw_spin_lock(); us| } us| } | mntput() { | mntput_no_expire() { us| vfsmount_lock_local_lock(); us| mnt_add_count(); us| vfsmount_lock_local_unlock(); us| } us| } us| } コールグラフ Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 9 “Irqsoff” Tracer • 最大の割り込み禁止区間を検出 # irqsoff latency trace v1.1.5 on 3.8.0+ # -------------------------------------------------------------------# latency: 8013 us,#26/26, CPU#1 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:2) # ----------------# | task: at-spi2-registr-1185 (uid:1000 nice:0 policy:0 rt_prio:0) # ----------------# => started at: __wake_up_sync_key # => ended at: __wake_up_sync_key # at-spi2--1185 0us : _raw_spin_lock_irqsave <-__wake_up_sync_key at-spi2--1185 0us : __wake_up_common <-__wake_up_sync_key at-spi2--1185 1us : ep_poll_callback <-__wake_up_common at-spi2--1185 5us : native_smp_send_reschedule <-try_to_wake_up at-spi2--1185 5us!: flat_send_IPI_mask <-native_smp_send_reschedule at-spi2--1185 8012us : ttwu_stat <-try_to_wake_up at-spi2--1185 8013us : _raw_spin_unlock_irqrestore <-try_to_wake_up at-spi2--1185 8013us : _raw_spin_unlock_irqrestore <-ep_poll_callback at-spi2--1185 8013us : _raw_spin_unlock_irqrestore <-__wake_up_sync_key at-spi2--1185 8014us : _raw_spin_unlock_irqrestore <-__wake_up_sync_key at-spi2--1185 8014us+: trace_hardirqs_on <-__wake_up_sync_key Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 10 ftrace全体像 common components debugfs I/F ring buffer plugin tracers function irqsoff wakeup stack trace trace events hook mechanisms mcount tracepoint kprobes Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 11 ftrace使い方 • debugfs経由で操作 # mount debugfs /sys/kernel/debug/ 擬似ファイルを echo とか cat する • 他にも下記のツールが利用可能 – trace-cmd （コマンドラインツール） – kernelshark （GUI） Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 12 /sys/kernel/debug/tracing/ tracing/ current events/ options/ per_cpu/ _tracer Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved trace 13 current_tracer • （プラグイン）トレーサを設定 – 初期状態はnop # echo function > current_tracer # echo irqsoff > current_tracer – trace eventやstack tracerは並行して利用できる Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 14 トレースバッファ • トレース結果を記録しておくためのバッファ • ロックレス・リングバッファ – 記録と読み出しを並行して行える • CPU毎にバッファを持つ CPU 0 CPU 1 CPU 2 CPU 3 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 15 trace • trace – トレースバッファの読み出し # cat trace – テキスト形式 – バッファ内のデータは消費されない – 書き込み可能＆O_TRUNCでopenするとクリア # echo > trace Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 16 trace_pipe, trace_pipe_raw • trace_pipe – “trace”に似ている – バッファ内のデータを消費する点が異なる • trace_pipe_raw – バイナリ形式で出力 – splice(2)で別のファイルにゼロコピー転送が可能 – per cpuのみ Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 17 options/ • トレースの挙動や結果表示の細かい設定 • 例: options/overwrite – バッファが満杯になった時に上書きするか、記録を やめるかを選べる • 1: 古いイベントを捨てる(default)＝上書き • 0: 新しいイベントを捨てる＝それ以上の記録を停止 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 18 events/ • events/event_class/event_name/enable – 特定のイベントを有効化（１）／無効化（０） # echo 1 > events/kmem/kmalloc/enable # echo 1 > events/kmem/enable Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 19 filter • 特定の条件を満たすイベントだけを記録できる # cd events/signal/signal_generate/ # echo "(sig == 5 || sig >= 10) && comm != bash” > filter Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 20 trace_marker • ユーザ空間からトレースバッファにイベントを記 録する • write(2)で好きな文字列を書き込み • チェックポイントを付けたい時に便利 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 21 Ftraceの動向 • 最近入った/入る予定の機能 – kprobes – uprobes – スナップショット – マルチバッファ – function-trigger – trace_clock (x86-tsc, perf, uptime) Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 22 Kprobes event (2.6.33~) • 動いているカーネルの好きな場所にイベントを 埋め込める – カーネルの改造不要 # echo ‘p:myprobe do_sys_open dfd=%ax filename=%dx flags=%cx mode=+4($stack)‘ > kprobe_events Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved ¥ ¥ ¥ ¥ ¥ 23 Uprobes event (3.5~) • Kprobesのユーザ空間版 • アプリの好きな場所にイベントを埋め込める – アプリの改造不要 • イベントはftraceのバッファに統合される Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 24 Snapshot (3.9~) • トレースを止めずに、ある瞬間のバッファの スナップショットを取る機能 • 予備のトレースバッファを用意しておいて、 好きなタイミングで切り替える 1.error ⇒Snapshot 記録処理 2.swap Spare buffer 3. continue tracing Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 25 Snapshot • 使い方: “snapshot”ファイルに1を書き込む – スナップショットを取る（バッファも割り当てる） # echo 1 > snapshot – スナップショットを読む # cat snapshot – スナップショット・バッファを解放する # echo 0 > snapshot – バッファの割当て時間が気になる場合は、あらかじ め1を書いておいて、その後スナップショットを取る Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 26 Snapshot • その後、Stevenが色々強化してくれた – per_cpu snapshot – snapshot_raw Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 27 Multi-buffer (3.10~?) • トレースバッファを用途別に複数個使い分ける 機能 – 今までは１つのグローバル・バッファしか無かった global buffer CPU 0 CPU 1 CPU 2 CPU 3 + instance 1 instance N CPU 0 CPU 1 CPU 0 CPU 1 CPU 2 CPU 3 CPU 2 CPU 3 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 28 Multi-buffer • バッファの個数はmkdir/rmdirで動的に変更可能 # cd instances/ # mkdir buf_1 # ls buf_1 buffer_size_kb buffer_total_size_kb events free_buffer per_cpu set_event snapshot trace trace_clock trace_marker trace_options trace_pipe tracing_on Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 29 Multi-buffer • 今のところ、instances以下のバッファでは Trace Eventsのみ利用可能 – プラグイントレーサは利用不可 • 3.11でマルチトレーサが入る予定 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 30 Function-trigger • 特定の関数が呼ばれた時にアクションを起こす • アクションの例 – トレース全体のON/OFF – 特定のトレースイベントのON/OFF – スナップショットを取る – スタックトレースを取る 3.10~? # echo ‘vfs_read:snapshot:1’ ¥ > set_ftrace_filter Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 31 trace_clock • “trace_clock”ファイルに書き込むことで タイムスタンプの種類を変更できる – local – global – counter – x86-tsc (3.8~) – uptime (3.10~?) – perf (3.10~?) Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 32 まとめ • ftraceを使うと様々なトレースが可能 • debugfsベースのインタフェースで操作 • 多くの機能が追加されて更に便利に！ Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 33 参考資料 • linux/Documentation/trace/ftrace.txt – 最近updateされたのでオススメ • Steven Rostedt, “Ftrace Linux Kernel Tracing”, LinuxCon Japan 2010 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 34 商標等 • Linuxは、Linus Torvalds氏の日本およびその 他の国における登録商標あるいは商標です。 Copyright (c) 2013 Hitachi LTD., Yokohama Research Lab. All rights reserved 35
© Copyright 2024 ExpyDoc
