mirror of
https://github.com/brendangregg/perf-tools.git
synced 2025-11-30 23:16:03 +07:00
127 lines
4.3 KiB
Plaintext
127 lines
4.3 KiB
Plaintext
Demonstrations of funccount, the Linux ftrace version.
|
|
|
|
|
|
Tracing all kernel functions that start with "bio_" (which would be block
|
|
interface functions), and counting how many times they were executed until
|
|
Ctrl-C is hit:
|
|
|
|
# ./funccount 'bio_*'
|
|
Tracing "bio_*"... Ctrl-C to end.
|
|
^C
|
|
FUNC COUNT
|
|
bio_attempt_back_merge 26
|
|
bio_get_nr_vecs 361
|
|
bio_alloc 536
|
|
bio_alloc_bioset 536
|
|
bio_endio 536
|
|
bio_free 536
|
|
bio_fs_destructor 536
|
|
bio_init 536
|
|
bio_integrity_enabled 536
|
|
bio_put 729
|
|
bio_add_page 1004
|
|
|
|
Note that these counts are performed in-kernel context, using the ftrace
|
|
function profiler, which means this is a (relatively) low overhead technique.
|
|
Test yourself to quantify overhead.
|
|
|
|
|
|
As was demonstrated here, wildcards can be used. Individual functions can also
|
|
be specified. For example, all of the following are valid arguments:
|
|
|
|
bio_init
|
|
bio_*
|
|
*init
|
|
*bio*
|
|
|
|
A "*" within a string (eg, "bio*init") is not supported.
|
|
|
|
The full list of what can be traced is in:
|
|
/sys/kernel/debug/tracing/available_filter_functions, which can be grep'd to
|
|
check what is there. Note that grep uses regular expressions, whereas
|
|
funccount uses globbing for wildcards.
|
|
|
|
|
|
Counting all "tcp_" kernel functions, and printing a summary every one second:
|
|
|
|
# ./funccount -i 1 -t 5 'tcp_*'
|
|
Tracing "tcp_*". Top 5 only... Ctrl-C to end.
|
|
|
|
FUNC COUNT
|
|
tcp_cleanup_rbuf 386
|
|
tcp_service_net_dma 386
|
|
tcp_established_options 549
|
|
tcp_v4_md5_lookup 560
|
|
tcp_v4_md5_do_lookup 890
|
|
|
|
FUNC COUNT
|
|
tcp_service_net_dma 498
|
|
tcp_cleanup_rbuf 499
|
|
tcp_established_options 664
|
|
tcp_v4_md5_lookup 672
|
|
tcp_v4_md5_do_lookup 1071
|
|
|
|
[...]
|
|
|
|
Neat.
|
|
|
|
|
|
Tracing all "ext4*" kernel functions for 10 seconds, and printing the top 25:
|
|
|
|
# ./funccount -t 25 -d 10 'ext4*'
|
|
Tracing "ext4*" for 10 seconds. Top 25 only...
|
|
|
|
FUNC COUNT
|
|
ext4_inode_bitmap 840
|
|
ext4_meta_trans_blocks 840
|
|
ext4_ext_drop_refs 843
|
|
ext4_find_entry 845
|
|
ext4_discard_preallocations 1008
|
|
ext4_free_inodes_count 1120
|
|
ext4_group_desc_csum 1120
|
|
ext4_group_desc_csum_set 1120
|
|
ext4_getblk 1128
|
|
ext4_es_free_extent 1328
|
|
ext4_map_blocks 1471
|
|
ext4_es_lookup_extent 1751
|
|
ext4_mb_check_limits 1873
|
|
ext4_es_lru_add 2031
|
|
ext4_data_block_valid 2312
|
|
ext4_journal_check_start 3080
|
|
ext4_mark_inode_dirty 5320
|
|
ext4_get_inode_flags 5955
|
|
ext4_get_inode_loc 5955
|
|
ext4_mark_iloc_dirty 5955
|
|
ext4_reserve_inode_write 5955
|
|
ext4_inode_table 7076
|
|
ext4_get_group_desc 8476
|
|
ext4_has_inline_data 9492
|
|
ext4_inode_touch_time_cmp 38980
|
|
|
|
Ending tracing...
|
|
|
|
So ext4_inode_touch_time_cmp() was called the most frequently, at 38,980 times.
|
|
This may be normal, this may not. The purpose of this tool is to give you one
|
|
view of how one or many kernel functions are executed. Previously I had little
|
|
idea what ext4 was doing internally. Now I know the top 25 functions, and their
|
|
rate, and can begin researching them from the source code.
|
|
|
|
|
|
Use -h to print the USAGE message:
|
|
|
|
# ./funccount -h
|
|
USAGE: funccount [-hT] [-i secs] [-d secs] [-t top] funcstring
|
|
-d seconds # total duration of trace
|
|
-h # this usage message
|
|
-i seconds # interval summary
|
|
-t top # show top num entries only
|
|
-T # include timestamp (for -i)
|
|
eg,
|
|
funccount 'vfs*' # trace all funcs that match "vfs*"
|
|
funccount -d 5 'tcp*' # trace "tcp*" funcs for 5 seconds
|
|
funccount -t 10 'ext3*' # show top 10 "ext3*" funcs
|
|
funccount -i 1 'ext3*' # summary every 1 second
|
|
funccount -i 1 -d 5 'ext3*' # 5 x 1 second summaries
|
|
|
|
See the man page and example file for more info.
|