ablog

funcgraph で Linux カーネル内のボトルネックをミクロに追跡する

Linux, ftrace

perf + Flame Graphs で Linux カーネル内のボトルネックを特定する - ablog

で Linux カーネル内のボトルネックをマクロに追跡する方法を紹介しましたが*1、

• strace でI/Oシステムコールのレスポンスを調べると遅く*2、
• iostat の await でカーネルのブロックレイヤーのI/Oレスポンスを調べると速い場合、

システムコールインターフェースとカーネルのブロックレイヤーの中間(ファイルシステムレイヤーなど)で詰まっていると考えられます*3。

このようなケースで、1回のシステムコール発行の所要時間の内訳*4をミクロに追跡には Brendan Gregg の funcgraph が便利です*5。

実行結果

# ./funcgraph -Htp 4511 vfs_write
Tracing "vfs_write" for PID 4511... Ctrl-C to end.
# tracer: function_graph
#
#     TIME        CPU  DURATION                  FUNCTION CALLS
#      |          |     |   |                     |   |   |   |
  935.579600 |   3)               |  vfs_write() {
  935.579602 |   3)               |    rw_verify_area() {
  935.579602 |   3)               |      security_file_permission() {
  935.579602 |   3)   0.085 us    |        cap_file_permission();
  935.579603 |   3)   0.810 us    |      }
  935.579603 |   3)   1.367 us    |    }
  935.579604 |   3)               |    do_sync_write() {
  935.579604 |   3)               |      pipe_write() {
  935.579604 |   3)               |        mutex_lock() {
  935.579604 |   3)   0.044 us    |          _cond_resched();
  935.579605 |   3)   0.434 us    |        }
  935.579605 |   3)   0.159 us    |        pipe_iov_copy_from_user();
  935.579606 |   3)   0.097 us    |        mutex_unlock();
  935.579606 |   3)               |        __wake_up_sync_key() {
  935.579606 |   3)   0.096 us    |          _raw_spin_lock_irqsave();
  935.579607 |   3)   0.062 us    |          __wake_up_common();
  935.579607 |   3)   0.070 us    |          _raw_spin_unlock_irqrestore();
  935.579608 |   3)   1.441 us    |        }
  935.579608 |   3)   0.133 us    |        kill_fasync();
  935.579609 |   3)               |        file_update_time() {
  935.579609 |   3)               |          current_fs_time() {
  935.579609 |   3)   0.046 us    |            current_kernel_time();
  935.579610 |   3)   0.048 us    |            timespec_trunc();
  935.579610 |   3)   0.881 us    |          }
  935.579610 |   3)               |          mnt_want_write_file() {
  935.579611 |   3)   0.257 us    |            mnt_want_write();
  935.579611 |   3)   0.764 us    |          }
  935.579611 |   3)   0.225 us    |          __mark_inode_dirty();
  935.579612 |   3)   0.044 us    |          mnt_drop_write();
  935.579612 |   3)   3.495 us    |        }
  935.579613 |   3)   8.489 us    |      }
  935.579613 |   3)   9.035 us    |    }
  935.579613 |   3)   0.055 us    |    __fsnotify_parent();
  935.579613 |   3)               |    fsnotify() {
  935.579614 |   3)   0.164 us    |      __srcu_read_lock();
  935.579614 |   3)   0.044 us    |      __srcu_read_unlock();
  935.579615 |   3)   1.253 us    |    }
  935.579615 |   3) + 13.624 us   |  }

手順

# curl -L -O https://raw.githubusercontent.com/brendangregg/perf-tools/master/kernel/funcgraph
# chmod u+x funcgraph
# mount -t debugfs debugfs /sys/kernel/debug
# ps -ef|grep [c]hrome
# ./funcgraph -Htp 4511 vfs_write

参考

• perf-tools/funcgraph at master ? brendangregg/perf-tools ? GitHub
• Ftrace: The hidden light switch [LWN.net]
• Ftrace と Systrace - steps to phantasien

<iframe src="//www.slideshare.net/slideshow/embed_code/key/iHwlnb2xUcp0Tw" width="425" height="355" frameborder="0" marginwidth="0" marginheight="0" scrolling="no" style="border:1px solid #CCC; border-width:1px; margin-bottom:5px; max-width: 100%;" allowfullscreen> </iframe>

関連

• 「シンプルでシステマチックなLinux性能分析方法」 @ db tech showcase 東京 2014 - ablog

ツイートする

Permalink | コメント(0) | トラックバック(0) | 08:48