| Demonstrations of stackcount, the Linux eBPF/bcc version. | |
| This program traces functions and frequency counts them with their entire | |
| stack trace, summarized in-kernel for efficiency. For example, counting | |
| stack traces that led to the submit_bio() kernel function, which creates | |
| block device I/O: | |
| # ./stackcount submit_bio | |
| Tracing 1 functions for "submit_bio"... Hit Ctrl-C to end. | |
| ^C | |
| submit_bio | |
| submit_bh | |
| journal_submit_commit_record.isra.13 | |
| jbd2_journal_commit_transaction | |
| kjournald2 | |
| kthread | |
| ret_from_fork | |
| mb_cache_list | |
| 1 | |
| submit_bio | |
| __block_write_full_page.constprop.39 | |
| block_write_full_page | |
| blkdev_writepage | |
| __writepage | |
| write_cache_pages | |
| generic_writepages | |
| do_writepages | |
| __writeback_single_inode | |
| writeback_sb_inodes | |
| __writeback_inodes_wb | |
| 2 | |
| submit_bio | |
| __block_write_full_page.constprop.39 | |
| block_write_full_page | |
| blkdev_writepage | |
| __writepage | |
| write_cache_pages | |
| generic_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_fdatawrite | |
| fdatawrite_one_bdev | |
| 36 | |
| submit_bio | |
| submit_bh | |
| jbd2_journal_commit_transaction | |
| kjournald2 | |
| kthread | |
| ret_from_fork | |
| mb_cache_list | |
| 38 | |
| submit_bio | |
| ext4_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_flush | |
| ext4_alloc_da_blocks | |
| ext4_rename | |
| ext4_rename2 | |
| vfs_rename | |
| sys_rename | |
| entry_SYSCALL_64_fastpath | |
| 79 | |
| Detaching... | |
| The output shows unique stack traces, in order from leaf (on-CPU) to root, | |
| followed by their occurrence count. The last stack trace in the above output | |
| shows syscall handling, ext4_rename(), and filemap_flush(): looks like an | |
| application issued file rename has caused back end disk I/O due to ext4 | |
| block allocation and a filemap_flush(). | |
| Now adding the -P option to display stacks separately for each process: | |
| # ./stackcount -P submit_bio | |
| Tracing 1 functions for "submit_bio"... Hit Ctrl-C to end. | |
| ^C | |
| submit_bio | |
| ext4_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_flush | |
| ext4_alloc_da_blocks | |
| ext4_release_file | |
| __fput | |
| ____fput | |
| task_work_run | |
| exit_to_usermode_loop | |
| syscall_return_slowpath | |
| entry_SYSCALL_64_fastpath | |
| [unknown] | |
| [unknown] | |
| tar [15069] | |
| 5 | |
| submit_bio | |
| ext4_bio_write_page | |
| mpage_submit_page | |
| mpage_map_and_submit_buffers | |
| ext4_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_flush | |
| ext4_alloc_da_blocks | |
| ext4_release_file | |
| __fput | |
| ____fput | |
| task_work_run | |
| exit_to_usermode_loop | |
| syscall_return_slowpath | |
| entry_SYSCALL_64_fastpath | |
| [unknown] | |
| [unknown] | |
| tar [15069] | |
| 15 | |
| submit_bio | |
| ext4_readpages | |
| __do_page_cache_readahead | |
| ondemand_readahead | |
| page_cache_async_readahead | |
| generic_file_read_iter | |
| __vfs_read | |
| vfs_read | |
| sys_read | |
| entry_SYSCALL_64_fastpath | |
| [unknown] | |
| tar [15069] | |
| 113 | |
| Detaching... | |
| The last stack trace in the above output shows syscall handling, sys_read(), | |
| vfs_read(), and then "readahead" functions: looks like an application issued | |
| file read has triggered read ahead. With "-P", the application can be seen | |
| after the stack trace, in this case, "tar [15069]" for the "tar" command, | |
| PID 15069. | |
| The order of printed stack traces is from least to most frequent. The most | |
| frequent in this case, the ext4_readpages() stack, was taken 113 times during | |
| tracing. | |
| The "[unknown]" frames are from user-level, since this simple workload is | |
| the tar command, which apparently has been compiled without frame pointers. | |
| It's a common compiler optimization, but it breaks frame pointer-based stack | |
| walkers. Similar broken stacks will be seen by other profilers and debuggers | |
| that use frame pointers. Hopefully your application preserves them so that | |
| the user-level stack trace is visible. So how does one get frame pointers, if | |
| your application doesn't have them to start with? For the current bcc (until | |
| it supports other stack walkers), you need to be running an application binaries | |
| that preserves frame pointers, eg, using gcc's -fno-omit-frame-pointer. That's | |
| about all I'll say here: this is a big topic that is not bcc/BPF specific. | |
| It can be useful to trace the path to submit_bio to explain unusual rates of | |
| disk IOPS. These could have in-kernel origins (eg, background scrub). | |
| Now adding the -d option to delimit kernel and user stacks: | |
| # ./stackcount -P -d submit_bio | |
| Tracing 1 functions for "submit_bio"... Hit Ctrl-C to end. | |
| ^C | |
| submit_bio | |
| submit_bh | |
| journal_submit_commit_record | |
| jbd2_journal_commit_transaction | |
| kjournald2 | |
| kthread | |
| ret_from_fork | |
| -- | |
| jbd2/xvda1-8 [405] | |
| 1 | |
| submit_bio | |
| submit_bh | |
| jbd2_journal_commit_transaction | |
| kjournald2 | |
| kthread | |
| ret_from_fork | |
| -- | |
| jbd2/xvda1-8 [405] | |
| 2 | |
| submit_bio | |
| ext4_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_flush | |
| ext4_alloc_da_blocks | |
| ext4_release_file | |
| __fput | |
| ____fput | |
| task_work_run | |
| exit_to_usermode_loop | |
| syscall_return_slowpath | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| [unknown] | |
| tar [15187] | |
| 5 | |
| submit_bio | |
| ext4_bio_write_page | |
| mpage_submit_page | |
| mpage_map_and_submit_buffers | |
| ext4_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_flush | |
| ext4_alloc_da_blocks | |
| ext4_release_file | |
| __fput | |
| ____fput | |
| task_work_run | |
| exit_to_usermode_loop | |
| syscall_return_slowpath | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| [unknown] | |
| tar [15187] | |
| 15 | |
| submit_bio | |
| ext4_readpages | |
| __do_page_cache_readahead | |
| ondemand_readahead | |
| page_cache_async_readahead | |
| generic_file_read_iter | |
| __vfs_read | |
| vfs_read | |
| sys_read | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| [unknown] | |
| [unknown] | |
| tar [15187] | |
| 171 | |
| Detaching... | |
| A "--" is printed between the kernel and user stacks. | |
| As a different example, here is the kernel function hrtimer_init_sleeper(): | |
| # ./stackcount.py -P -d hrtimer_init_sleeper | |
| Tracing 1 functions for "hrtimer_init_sleeper"... Hit Ctrl-C to end. | |
| ^C | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| containerd [16020] | |
| 1 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __pthread_cond_timedwait | |
| Monitor::IWait(Thread*, long) | |
| Monitor::wait(bool, long, bool) | |
| CompileQueue::get() | |
| CompileBroker::compiler_thread_loop() | |
| JavaThread::thread_main_inner() | |
| JavaThread::run() | |
| java_start(Thread*) | |
| start_thread | |
| java [4996] | |
| 1 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| [unknown] | |
| containerd [16020] | |
| 1 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __pthread_cond_timedwait | |
| VMThread::loop() | |
| VMThread::run() | |
| java_start(Thread*) | |
| start_thread | |
| java [4996] | |
| 3 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| dockerd [16008] | |
| 4 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| [unknown] | |
| dockerd [16008] | |
| 4 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __pthread_cond_timedwait | |
| Lio/netty/util/ThreadDeathWatcher$Watcher;::run | |
| Interpreter | |
| Interpreter | |
| call_stub | |
| JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*) | |
| JavaCalls::call_virtual(JavaValue*, KlassHandle, Symbol*, Symbol*, JavaCallArguments*, Thread*) | |
| JavaCalls::call_virtual(JavaValue*, Handle, KlassHandle, Symbol*, Symbol*, Thread*) | |
| thread_entry(JavaThread*, Thread*) | |
| JavaThread::thread_main_inner() | |
| JavaThread::run() | |
| java_start(Thread*) | |
| start_thread | |
| java [4996] | |
| 4 | |
| hrtimer_init_sleeper | |
| do_futex | |
| SyS_futex | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __pthread_cond_timedwait | |
| clock_gettime | |
| [unknown] | |
| java [4996] | |
| 79 | |
| Detaching... | |
| I was just trying to find a more interesting example. This output includes | |
| some Java stacks where user-level has been walked correctly (even includes a | |
| JIT symbol translation). dockerd and containerd don't have frame pointers | |
| (grumble), but Java does (which is running with -XX:+PreserveFramePointer). | |
| Here's another kernel function, ip_output(): | |
| # ./stackcount.py -P -d ip_output | |
| Tracing 1 functions for "ip_output"... Hit Ctrl-C to end. | |
| ^C | |
| ip_output | |
| ip_queue_xmit | |
| tcp_transmit_skb | |
| tcp_write_xmit | |
| __tcp_push_pending_frames | |
| tcp_push | |
| tcp_sendmsg | |
| inet_sendmsg | |
| sock_sendmsg | |
| sock_write_iter | |
| __vfs_write | |
| vfs_write | |
| SyS_write | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __write_nocancel | |
| [unknown] | |
| sshd [15015] | |
| 5 | |
| ip_output | |
| ip_queue_xmit | |
| tcp_transmit_skb | |
| tcp_write_xmit | |
| __tcp_push_pending_frames | |
| tcp_push | |
| tcp_sendmsg | |
| inet_sendmsg | |
| sock_sendmsg | |
| sock_write_iter | |
| __vfs_write | |
| vfs_write | |
| SyS_write | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __write_nocancel | |
| [unknown] | |
| [unknown] | |
| sshd [8234] | |
| 5 | |
| ip_output | |
| ip_queue_xmit | |
| tcp_transmit_skb | |
| tcp_write_xmit | |
| __tcp_push_pending_frames | |
| tcp_push | |
| tcp_sendmsg | |
| inet_sendmsg | |
| sock_sendmsg | |
| sock_write_iter | |
| __vfs_write | |
| vfs_write | |
| SyS_write | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| __write_nocancel | |
| sshd [15015] | |
| 7 | |
| Detaching... | |
| This time just sshd is triggering ip_output() calls. | |
| Watch what happens if I filter on kernel stacks only (-K) for ip_output(): | |
| # ./stackcount.py -K ip_output | |
| Tracing 1 functions for "ip_output"... Hit Ctrl-C to end. | |
| ^C | |
| ip_output | |
| ip_queue_xmit | |
| tcp_transmit_skb | |
| tcp_write_xmit | |
| __tcp_push_pending_frames | |
| tcp_push | |
| tcp_sendmsg | |
| inet_sendmsg | |
| sock_sendmsg | |
| sock_write_iter | |
| __vfs_write | |
| vfs_write | |
| SyS_write | |
| entry_SYSCALL_64_fastpath | |
| 13 | |
| Detaching... | |
| They have grouped together as a single unique stack, since the kernel part | |
| was the same. | |
| Here is just the user stacks, fetched during the kernel function ip_output(): | |
| # ./stackcount.py -P -U ip_output | |
| Tracing 1 functions for "ip_output"... Hit Ctrl-C to end. | |
| ^C | |
| [unknown] | |
| snmpd [1645] | |
| 1 | |
| __write_nocancel | |
| [unknown] | |
| [unknown] | |
| sshd [8234] | |
| 3 | |
| __write_nocancel | |
| sshd [15015] | |
| 4 | |
| I should really run a custom sshd with frame pointers so we can see its | |
| stack trace... | |
| User-space functions can also be traced if a library name is provided. For | |
| example, to quickly identify code locations that allocate heap memory for | |
| PID 4902 (using -p), by tracing malloc from libc ("c:malloc"): | |
| # ./stackcount -p 4902 c:malloc | |
| Tracing 1 functions for "malloc"... Hit Ctrl-C to end. | |
| ^C | |
| malloc | |
| rbtree_new | |
| main | |
| [unknown] | |
| 12 | |
| malloc | |
| _rbtree_node_new_internal | |
| _rbtree_node_insert | |
| rbtree_insert | |
| main | |
| [unknown] | |
| 1189 | |
| Detaching... | |
| Kernel stacks are absent as this didn't enter kernel code. | |
| Note that user-space uses of stackcount can be somewhat more limited because | |
| a lot of user-space libraries and binaries are compiled without frame-pointers | |
| as discussed earlier (the -fomit-frame-pointer compiler default) or are used | |
| without debuginfo. | |
| In addition to kernel and user-space functions, kernel tracepoints and USDT | |
| tracepoints are also supported. | |
| For example, to determine where threads are being created in a particular | |
| process, use the pthread_create USDT tracepoint: | |
| # ./stackcount -P -p $(pidof parprimes) u:pthread:pthread_create | |
| Tracing 1 functions for "u:pthread:pthread_create"... Hit Ctrl-C to end. | |
| ^C | |
| parprimes [11923] | |
| pthread_create@@GLIBC_2.2.5 | |
| main | |
| __libc_start_main | |
| [unknown] | |
| 7 | |
| You can use "readelf -n file" to see if it has USDT tracepoints. | |
| Similarly, to determine where context switching is happening in the kernel, | |
| use the sched:sched_switch kernel tracepoint: | |
| # ./stackcount -P t:sched:sched_switch | |
| __schedule | |
| schedule | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| kworker/0:2 [25482] | |
| 1 | |
| __schedule | |
| schedule | |
| schedule_hrtimeout_range_clock | |
| schedule_hrtimeout_range | |
| ep_poll | |
| SyS_epoll_wait | |
| entry_SYSCALL_64_fastpath | |
| epoll_wait | |
| Lsun/nio/ch/SelectorImpl;::lockAndDoSelect | |
| Lsun/nio/ch/SelectorImpl;::select | |
| Lio/netty/channel/nio/NioEventLoop;::select | |
| Lio/netty/channel/nio/NioEventLoop;::run | |
| Interpreter | |
| Interpreter | |
| call_stub | |
| JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*) | |
| JavaCalls::call_virtual(JavaValue*, KlassHandle, Symbol*, Symbol*, JavaCallArguments*, Thread*) | |
| JavaCalls::call_virtual(JavaValue*, Handle, KlassHandle, Symbol*, Symbol*, Thread*) | |
| thread_entry(JavaThread*, Thread*) | |
| JavaThread::thread_main_inner() | |
| JavaThread::run() | |
| java_start(Thread*) | |
| start_thread | |
| java [4996] | |
| 1 | |
| ... (omitted for brevity) | |
| __schedule | |
| schedule | |
| schedule_preempt_disabled | |
| cpu_startup_entry | |
| xen_play_dead | |
| arch_cpu_idle_dead | |
| cpu_startup_entry | |
| cpu_bringup_and_idle | |
| swapper/1 [0] | |
| 289 | |
| A -i option can be used to set an output interval, and -T to include a | |
| timestamp. For example: | |
| # ./stackcount.py -P -Tdi 1 submit_bio | |
| Tracing 1 functions for "submit_bio"... Hit Ctrl-C to end. | |
| 06:05:13 | |
| 06:05:14 | |
| submit_bio | |
| xfs_do_writepage | |
| write_cache_pages | |
| xfs_vm_writepages | |
| do_writepages | |
| __writeback_single_inode | |
| writeback_sb_inodes | |
| __writeback_inodes_wb | |
| wb_writeback | |
| wb_workfn | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/u16:1 [15686] | |
| 1 | |
| submit_bio | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/u16:0 [16007] | |
| 1 | |
| submit_bio | |
| xfs_buf_submit | |
| xlog_bdstrat | |
| xlog_sync | |
| xlog_state_release_iclog | |
| _xfs_log_force | |
| xfs_log_force | |
| xfs_fs_sync_fs | |
| sync_fs_one_sb | |
| iterate_supers | |
| sys_sync | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| sync [16039] | |
| 1 | |
| submit_bio | |
| submit_bh | |
| journal_submit_commit_record | |
| jbd2_journal_commit_transaction | |
| kjournald2 | |
| kthread | |
| ret_from_fork | |
| -- | |
| jbd2/xvda1-8 [405] | |
| 1 | |
| submit_bio | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/0:2 [25482] | |
| 2 | |
| submit_bio | |
| ext4_writepages | |
| do_writepages | |
| __writeback_single_inode | |
| writeback_sb_inodes | |
| __writeback_inodes_wb | |
| wb_writeback | |
| wb_workfn | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/u16:0 [16007] | |
| 4 | |
| submit_bio | |
| xfs_vm_writepages | |
| do_writepages | |
| __writeback_single_inode | |
| writeback_sb_inodes | |
| __writeback_inodes_wb | |
| wb_writeback | |
| wb_workfn | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/u16:1 [15686] | |
| 5 | |
| submit_bio | |
| __block_write_full_page | |
| block_write_full_page | |
| blkdev_writepage | |
| __writepage | |
| write_cache_pages | |
| generic_writepages | |
| blkdev_writepages | |
| do_writepages | |
| __filemap_fdatawrite_range | |
| filemap_fdatawrite | |
| fdatawrite_one_bdev | |
| iterate_bdevs | |
| sys_sync | |
| entry_SYSCALL_64_fastpath | |
| -- | |
| [unknown] | |
| sync [16039] | |
| 7 | |
| submit_bio | |
| submit_bh | |
| jbd2_journal_commit_transaction | |
| kjournald2 | |
| kthread | |
| ret_from_fork | |
| -- | |
| jbd2/xvda1-8 [405] | |
| 8 | |
| submit_bio | |
| ext4_bio_write_page | |
| mpage_submit_page | |
| mpage_map_and_submit_buffers | |
| ext4_writepages | |
| do_writepages | |
| __writeback_single_inode | |
| writeback_sb_inodes | |
| __writeback_inodes_wb | |
| wb_writeback | |
| wb_workfn | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/u16:0 [16007] | |
| 8 | |
| submit_bio | |
| __block_write_full_page | |
| block_write_full_page | |
| blkdev_writepage | |
| __writepage | |
| write_cache_pages | |
| generic_writepages | |
| blkdev_writepages | |
| do_writepages | |
| __writeback_single_inode | |
| writeback_sb_inodes | |
| __writeback_inodes_wb | |
| wb_writeback | |
| wb_workfn | |
| process_one_work | |
| worker_thread | |
| kthread | |
| ret_from_fork | |
| -- | |
| kworker/u16:0 [16007] | |
| 60 | |
| 06:05:15 | |
| 06:05:16 | |
| Detaching... | |
| This only included output for the 06:05:14 interval. The other internals | |
| did not span block device I/O. | |
| The -s output prints the return instruction offset for each function (aka | |
| symbol offset). Eg: | |
| # ./stackcount.py -P -s tcp_sendmsg | |
| Tracing 1 functions for "tcp_sendmsg"... Hit Ctrl-C to end. | |
| ^C | |
| tcp_sendmsg+0x1 | |
| sock_sendmsg+0x38 | |
| sock_write_iter+0x85 | |
| __vfs_write+0xe3 | |
| vfs_write+0xb8 | |
| SyS_write+0x55 | |
| entry_SYSCALL_64_fastpath+0x1e | |
| __write_nocancel+0x7 | |
| sshd [15015] | |
| 3 | |
| tcp_sendmsg+0x1 | |
| sock_sendmsg+0x38 | |
| sock_write_iter+0x85 | |
| __vfs_write+0xe3 | |
| vfs_write+0xb8 | |
| SyS_write+0x55 | |
| entry_SYSCALL_64_fastpath+0x1e | |
| __write_nocancel+0x7 | |
| sshd [8234] | |
| 3 | |
| Detaching... | |
| If it wasn't clear how one function called another, knowing the instruction | |
| offset can help you locate the lines of code from a disassembly dump. | |
| The -v output is verbose, and shows raw addresses: | |
| ./stackcount.py -P -v tcp_sendmsg | |
| Tracing 1 functions for "tcp_sendmsg"... Hit Ctrl-C to end. | |
| ^C | |
| ffffffff817b05c1 tcp_sendmsg | |
| ffffffff8173ea48 sock_sendmsg | |
| ffffffff8173eae5 sock_write_iter | |
| ffffffff81232b33 __vfs_write | |
| ffffffff812331b8 vfs_write | |
| ffffffff81234625 SyS_write | |
| ffffffff818739bb entry_SYSCALL_64_fastpath | |
| 7f120511e6e0 __write_nocancel | |
| sshd [8234] | |
| 3 | |
| ffffffff817b05c1 tcp_sendmsg | |
| ffffffff8173ea48 sock_sendmsg | |
| ffffffff8173eae5 sock_write_iter | |
| ffffffff81232b33 __vfs_write | |
| ffffffff812331b8 vfs_write | |
| ffffffff81234625 SyS_write | |
| ffffffff818739bb entry_SYSCALL_64_fastpath | |
| 7f919c5a26e0 __write_nocancel | |
| sshd [15015] | |
| 11 | |
| Detaching... | |
| A wildcard can also be used. Eg, all functions beginning with "tcp_send", | |
| kernel stacks only (-K) with offsets (-s): | |
| # ./stackcount -Ks 'tcp_send*' | |
| Tracing 14 functions for "tcp_send*"... Hit Ctrl-C to end. | |
| ^C | |
| tcp_send_delayed_ack0x1 | |
| tcp_rcv_established0x3b1 | |
| tcp_v4_do_rcv0x130 | |
| tcp_v4_rcv0x8e0 | |
| ip_local_deliver_finish0x9f | |
| ip_local_deliver0x51 | |
| ip_rcv_finish0x8a | |
| ip_rcv0x29d | |
| __netif_receive_skb_core0x637 | |
| __netif_receive_skb0x18 | |
| netif_receive_skb_internal0x23 | |
| 1 | |
| tcp_send_delayed_ack0x1 | |
| tcp_rcv_established0x222 | |
| tcp_v4_do_rcv0x130 | |
| tcp_v4_rcv0x8e0 | |
| ip_local_deliver_finish0x9f | |
| ip_local_deliver0x51 | |
| ip_rcv_finish0x8a | |
| ip_rcv0x29d | |
| __netif_receive_skb_core0x637 | |
| __netif_receive_skb0x18 | |
| netif_receive_skb_internal0x23 | |
| 4 | |
| tcp_send_mss0x1 | |
| inet_sendmsg0x67 | |
| sock_sendmsg0x38 | |
| sock_write_iter0x78 | |
| __vfs_write0xaa | |
| vfs_write0xa9 | |
| sys_write0x46 | |
| entry_SYSCALL_64_fastpath0x16 | |
| 7 | |
| tcp_sendmsg0x1 | |
| sock_sendmsg0x38 | |
| sock_write_iter0x78 | |
| __vfs_write0xaa | |
| vfs_write0xa9 | |
| sys_write0x46 | |
| entry_SYSCALL_64_fastpath0x16 | |
| 7 | |
| Detaching... | |
| Use -r to allow regular expressions. | |
| The -f option will emit folded output, which can be used as input to other | |
| tools including flame graphs. For example, with delimiters as well: | |
| # ./stackcount.py -P -df t:sched:sched_switch | |
| ^Csnmp-pass;[unknown];[unknown];[unknown];[unknown];[unknown];-;entry_SYSCALL_64_fastpath;SyS_select;core_sys_select;do_select;poll_schedule_timeout;schedule_hrtimeout_range;schedule_hrtimeout_range_clock;schedule;__schedule 1 | |
| kworker/7:0;-;ret_from_fork;kthread;worker_thread;schedule;__schedule 1 | |
| watchdog/0;-;ret_from_fork;kthread;smpboot_thread_fn;schedule;__schedule 1 | |
| snmp-pass;[unknown];[unknown];[unknown];[unknown];[unknown];-;entry_SYSCALL_64_fastpath;SyS_select;core_sys_select;do_select;poll_schedule_timeout;schedule_hrtimeout_range;schedule_hrtimeout_range_clock;schedule;__schedule 1 | |
| svscan;[unknown];-;entry_SYSCALL_64_fastpath;SyS_nanosleep;hrtimer_nanosleep;do_nanosleep;schedule;__schedule 1 | |
| python;[unknown];__select_nocancel;-;entry_SYSCALL_64_fastpath;SyS_select;core_sys_select;do_select;poll_schedule_timeout;schedule_hrtimeout_range;schedule_hrtimeout_range_clock;schedule;__schedule 1 | |
| kworker/2:0;-;ret_from_fork;kthread;worker_thread;schedule;__schedule 1 | |
| [...] | |
| Flame graphs visualize stack traces. For information about them and links | |
| to open source software, see http://www.brendangregg.com/flamegraphs.html . | |
| This folded output can be piped directly into flamegraph.pl (the Perl version). | |
| USAGE message: | |
| # ./stackcount -h | |
| usage: stackcount [-h] [-p PID] [-c CPU] [-i INTERVAL] [-D DURATION] [-T] [-r] | |
| [-s] [-P] [-K] [-U] [-v] [-d] [-f] [--debug] | |
| pattern | |
| Count events and their stack traces | |
| positional arguments: | |
| pattern search expression for events | |
| optional arguments: | |
| -h, --help show this help message and exit | |
| -p PID, --pid PID trace this PID only | |
| -c CPU, --cpu CPU trace this CPU only | |
| -i INTERVAL, --interval INTERVAL | |
| summary interval, seconds | |
| -D DURATION, --duration DURATION | |
| total duration of trace, seconds | |
| -T, --timestamp include timestamp on output | |
| -r, --regexp use regular expressions. Default is "*" wildcards | |
| only. | |
| -s, --offset show address offsets | |
| -P, --perpid display stacks separately for each process | |
| -K, --kernel-stacks-only | |
| kernel stack only | |
| -U, --user-stacks-only | |
| user stack only | |
| -v, --verbose show raw addresses | |
| -d, --delimited insert delimiter between kernel/user stacks | |
| -f, --folded output folded format | |
| --debug print BPF program before starting (for debugging | |
| purposes) | |
| examples: | |
| ./stackcount submit_bio # count kernel stack traces for submit_bio | |
| ./stackcount -d ip_output # include a user/kernel stack delimiter | |
| ./stackcount -s ip_output # show symbol offsets | |
| ./stackcount -sv ip_output # show offsets and raw addresses (verbose) | |
| ./stackcount 'tcp_send*' # count stacks for funcs matching tcp_send* | |
| ./stackcount -r '^tcp_send.*' # same as above, using regular expressions | |
| ./stackcount -Ti 5 ip_output # output every 5 seconds, with timestamps | |
| ./stackcount -p 185 ip_output # count ip_output stacks for PID 185 only | |
| ./stackcount -p 185 c:malloc # count stacks for malloc in PID 185 | |
| ./stackcount t:sched:sched_fork # count stacks for sched_fork tracepoint | |
| ./stackcount -p 185 u:node:* # count stacks for all USDT probes in node | |
| ./stackcount -c 1 put_prev_entity # count put_prev_entity stacks for CPU 1 only | |
| ./stackcount -K t:sched:sched_switch # kernel stacks only | |
| ./stackcount -U t:sched:sched_switch # user stacks only |