Red Hat Training

A Red Hat training course is available for RHEL 8

Chapter 40. Profiling kernel activity with SystemTap

You can profile the kernel activity by monitoring function calls with the following scripts.

40.1. Counting function calls with SystemTap

You can use the functioncallcount.stp SystemTap script to count specific kernel function calls. You can also use this script to target multiple kernel functions.

Prerequisites

Procedure

  • Run the functioncallcount.stp script: 

    # stap --example functioncallcount.stp 'argument'

    This script takes the targeted kernel function as an argument. You can use the argument wildcards to target multiple kernel functions up to a certain extent.

    The output of the script, in alphabetical order, contains the names of the functions called and how many times it was called during the sample time.

    Consider the following example: 

    # stap -w -v --example functioncallcount.stp "*@mm*.c" -c /bin/true

    where:

  • -w : Suppresses warnings.
  • -v : Makes the output of starting kernel visible.

  • -c command : Tells SystemTap to count function calls during the execution of a command, in this example being /bin/true.

    The output should look similar to the following: 

    [...]
__vma_link 97
__vma_link_file 66
__vma_link_list 97
__vma_link_rb 97
__xchg 103
add_page_to_active_list 102
add_page_to_inactive_list 19
add_to_page_cache 19
add_to_page_cache_lru 7
all_vm_events 6
alloc_pages_node 4630
alloc_slabmgmt 67
anon_vma_alloc 62
anon_vma_free 62
anon_vma_lock 66
anon_vma_prepare 98
anon_vma_unlink 97
anon_vma_unlock 66
arch_get_unmapped_area_topdown 94
arch_get_unmapped_exec_area 3
arch_unmap_area_topdown 97
atomic_add 2
atomic_add_negative 97
atomic_dec_and_test 5153
atomic_inc 470
atomic_inc_and_test 1
[...]

40.2. Tracing function calls with SystemTap

You can use the para-callgraph.stp SystemTap script to trace function calls and function returns.

Prerequisites

Procedure

  • Run the para-callgraph.stp script. 
# stap --example para-callgraph.stp 'argument1' 'argument2'

The script para-callgraph.stp takes two command-line arguments:

  1. The name of the function(s) whose entry/exit you’d like to trace.
  2. An optional trigger function, which enables or disables tracing on a per-thread basis. Tracing in each thread will continue as long as the trigger function has not exited yet.

Consider the following example: 

# stap -wv --example para-callgraph.stp 'kernel.function("*@fs/proc.c*")' 'kernel.function("vfs_read")' -c "cat /proc/sys/vm/* || true"

where:

  • -w : Suppresses warnings.
  • -v : Makes the output of starting kernel visible.
  • -c command : Tells SystemTap to count function calls during the execution of a command, in this example being /bin/true.

The output should look similar to the following: 

[...]
   267 gnome-terminal(2921): <-do_sync_read return=0xfffffffffffffff5
   269 gnome-terminal(2921):<-vfs_read return=0xfffffffffffffff5
     0 gnome-terminal(2921):->fput file=0xffff880111eebbc0
     2 gnome-terminal(2921):<-fput
     0 gnome-terminal(2921):->fget_light fd=0x3 fput_needed=0xffff88010544df54
     3 gnome-terminal(2921):<-fget_light return=0xffff8801116ce980
     0 gnome-terminal(2921):->vfs_read file=0xffff8801116ce980 buf=0xc86504 count=0x1000 pos=0xffff88010544df48
     4 gnome-terminal(2921): ->rw_verify_area read_write=0x0 file=0xffff8801116ce980 ppos=0xffff88010544df48 count=0x1000
     7 gnome-terminal(2921): <-rw_verify_area return=0x1000
    12 gnome-terminal(2921): ->do_sync_read filp=0xffff8801116ce980 buf=0xc86504 len=0x1000 ppos=0xffff88010544df48
    15 gnome-terminal(2921): <-do_sync_read return=0xfffffffffffffff5
    18 gnome-terminal(2921):<-vfs_read return=0xfffffffffffffff5
     0 gnome-terminal(2921):->fput file=0xffff8801116ce980

40.3. Determining time spent in kernel and user space with SystemTap

You can use the thread-times.stp SystemTap script to determine the amount of time any given thread is spending in either the kernel or user-space.

Prerequisites

Procedure

  • Run the thread-times.stp script: 

    # stap --example thread-times.stp

    This script will display the top 20 processes taking up CPU time during a 5-second period, along with the total number of CPU ticks made during the sample. The output of this script also notes the percentage of CPU time each process used, as well as whether that time was spent in kernel space or user space. 

    tid   %user %kernel (of 20002 ticks)
  0   0.00%  87.88%
32169   5.24%   0.03%
9815   3.33%   0.36%
9859   0.95%   0.00%
3611   0.56%   0.12%
9861   0.62%   0.01%
11106   0.37%   0.02%
32167   0.08%   0.08%
3897   0.01%   0.08%
3800   0.03%   0.00%
2886   0.02%   0.00%
3243   0.00%   0.01%
3862   0.01%   0.00%
3782   0.00%   0.00%
21767   0.00%   0.00%
2522   0.00%   0.00%
3883   0.00%   0.00%
3775   0.00%   0.00%
3943   0.00%   0.00%
3873   0.00%   0.00%

40.4. Monitoring polling applications with SystemTap

You can use timeout.stp SystemTap script to identify and monitor which applications are polling. Doing so allows you to track unnecessary or excessive polling, which helps you pinpoint areas for improvement in terms of CPU usage and power savings.

Prerequisites

Procedure

  • Run the timeout.stp script: 

    # stap --example timeout.stp

    This script will track how many times each application uses the following system calls over time:

  • poll
  • select
  • epoll
  • itimer
  • futex
  • nanosleep
  • signal

In this example output you can see which process used which system call and how many times. 

uid |   poll  select   epoll  itimer   futex nanosle  signal| process
28937 | 148793       0       0    4727   37288       0       0| firefox
22945 |      0   56949       0       1       0       0       0| scim-bridge
  0 |      0       0       0   36414       0       0       0| swapper
4275 |  23140       0       0       1       0       0       0| mixer_applet2
4191 |      0   14405       0       0       0       0       0| scim-launcher
22941 |   7908       1       0      62       0       0       0| gnome-terminal
4261 |      0       0       0       2       0    7622       0| escd
3695 |      0       0       0       0       0    7622       0| gdm-binary
3483 |      0    7206       0       0       0       0       0| dhcdbd
4189 |   6916       0       0       2       0       0       0| scim-panel-gtk
1863 |   5767       0       0       0       0       0       0| iscsid

40.5. Tracking most frequently used system calls with SystemTap

You can use the topsys.stp SystemTap script to list the top 20 system calls used by the system per 5-second interval. It also lists how many times each system call was used during that period.

Prerequisites

Procedure

  • Run the topsys.stp script: 

    # stap --example topsys.stp

    Consider the following example: 

    # stap -v --example topsys.stp

    where -v makes the output of starting kernel visible.

    The output should look similar to the following: 

--------------------------------------------------------------
                  SYSCALL      COUNT
             gettimeofday       1857
                     read       1821
                    ioctl       1568
                     poll       1033
                    close        638
                     open        503
                   select        455
                    write        391
                   writev        335
                    futex        303
                  recvmsg        251
                   socket        137
            clock_gettime        124
           rt_sigprocmask        121
                   sendto        120
                setitimer        106
                     stat         90
                     time         81
                sigreturn         72
                    fstat         66
--------------------------------------------------------------

40.6. Tracking system call volume per process with SystemTap

You can use the syscalls_by_proc.stp SystemTap script to see which processes are performing the highest volume of system calls. It displays 20 processes performing the most of system calls.

Prerequisites

Procedure

  • Run the syscalls_by_proc.stp script: 

    # stap --example syscalls_by_proc.stp

    Output of the syscalls_by_proc.stp script looks similar to the following: 

    Collecting data... Type Ctrl-C to exit and display results
#SysCalls  Process Name
1577       multiload-apple
692        synergyc
408        pcscd
376        mixer_applet2
299        gnome-terminal
293        Xorg
206        scim-panel-gtk
95         gnome-power-man
90         artsd
85         dhcdbd
84         scim-bridge
78         gnome-screensav
66         scim-launcher
[...]