bcc-tools工具之offcputime

Posted 2021-03-15 haoxing990

先了解什么是off-cpu

• On-CPU: where threads are spending time running on-CPU.
• Off-CPU: where time is spent waiting while blocked on I/O, locks, timers, paging/swapping, etc.

从上面的意思基本上了解offcputime的意思是什么了:用于测量某一进程被阻塞的时间。

老样子，还是从help开始说起：

usage: offcputime [-h] [-p PID | -t TID | -u | -k] [-U | -K] [-d] [-f]
                  [--stack-storage-size STACK_STORAGE_SIZE]
                  [-m MIN_BLOCK_TIME] [-M MAX_BLOCK_TIME] [--state STATE]
                  [duration]

Summarize off-CPU time by stack trace

positional arguments:
  duration              duration of trace, in seconds

optional arguments:
  -h, --help            show this help message and exit
  -p PID, --pid PID     trace this PID only    #仅仅跟踪某一进程阻塞时间
  -t TID, --tid TID     trace this TID only　　 #仅仅跟踪某一线程阻塞时间
  -u, --user-threads-only
                        user threads only (no kernel threads) #仅仅跟踪用户态而非内核态线程阻塞时间
  -k, --kernel-threads-only
                        kernel threads only (no user threads) #仅仅跟踪内核态线程阻塞时间
  -U, --user-stacks-only
                        show stacks from user space only (no kernel space  #仅仅显示用户态调用栈关系
                        stacks)
  -K, --kernel-stacks-only                                     #仅仅显示内核态调用栈关系
                        show stacks from kernel space only (no user space
                        stacks)
  -d, --delimited       insert delimiter between kernel/user stacks  #将内核态和用户态调用栈分割开来
  -f, --folded          output folded format                   # 采用折叠模式输出d
  --stack-storage-size STACK_STORAGE_SIZE　　　　　　　　　　　　  # 设置栈跟踪过程存储空间大小
                        the number of unique stack traces that can be stored
                        and displayed (default 1024)
  -m MIN_BLOCK_TIME, --min-block-time MIN_BLOCK_TIME           #只打印阻塞时间不小于xxx us的进程情况       
                        the amount of time in microseconds over which we store  
                        traces (default 1)
  -M MAX_BLOCK_TIME, --max-block-time MAX_BLOCK_TIME           #只打印阻塞时间不大于xxx us的进程情况
                        the amount of time in microseconds under which we
                        store traces (default U64_MAX)
  --state STATE         filter on this thread state bitmask (eg, 2 ==   #追踪进程为某种状态的阻塞情况，例如不可中断
                        TASK_UNINTERRUPTIBLE) see include/linux/sched.h

./offcputime -K

显示所有进程内核态栈调用情况

schedule
    schedule_timeout
    io_schedule_timeout
    bit_wait_io
    __wait_on_bit
    wait_on_page_bit_killable
    __lock_page_or_retry
    filemap_fault
    __do_fault
    handle_mm_fault
    __do_page_fault
    do_page_fault
    page_fault
    chmod
        13  表示阻塞时间为13us

    schedule
    rcu_nocb_kthread
    kthread
    ret_from_fork
    ddebug_tables
    rcuos/0
        22 表示阻塞时间为22us

./offcputime -K -f 5

采用折叠方式显示栈调用流程

bash;entry_SYSCALL_64_fastpath;sys_read;vfs_read;__vfs_read;tty_read;n_tty_read;call_rwsem_down_read_failed;rwsem_down_read_failed;schedule 8
yes;entry_SYSCALL_64_fastpath;sys_write;vfs_write;__vfs_write;tty_write;n_tty_write;call_rwsem_down_read_failed;rwsem_down_read_failed;schedule 14
run;page_fault;do_page_fault;__do_page_fault;handle_mm_fault;__do_fault;filemap_fault;__lock_page_or_retry;wait_on_page_bit_killable;__wait_on_bit;bit_wait_io;io_schedule_timeout;schedule_timeout;schedule 33
rcuos/4;ret_from_fork;kthread;rcu_nocb_kthread;schedule 45
bash;entry_SYSCALL_64_fastpath;sys_read;vfs_read;__vfs_read;pipe_read;pipe_wait;schedule 88
run;page_fault;do_page_fault;__do_page_fault;handle_mm_fault;__do_fault;filemap_fault;__lock_page_or_retry;wait_on_page_bit_killable;__wait_on_bit;bit_wait_io;io_schedule_timeout;schedule_timeout;schedule 108
jbd2/xvda1-8;mb_cache_list;ret_from_fork;kthread;kjournald2;jbd2_journal_commit_transaction;__wait_on_buffer;out_of_line_wait_on_bit;__wait_on_bit;bit_wait_io;io_schedule_timeout;schedule_timeout;schedule 828
jbd2/xvda1-8;mb_cache_list;ret_from_fork;kthread;kjournald2;jbd2_journal_commit_transaction;__wait_on_buffer;out_of_line_wait_on_bit;__wait_on_bit;bit_wait_io;io_schedule_timeout;schedule_timeout;schedule 6201
supervise;entry_SYSCALL_64_fastpath;sys_rename;dput;__dentry_kill;iput;evict;ext4_evict_inode;truncate_inode_pages_final;truncate_inode_pages_range;wait_on_page_bit;__wait_on_bit;bit_wait_io;io_schedule_timeout;schedule_timeout;schedule 41049
run;entry_SYSCALL_64_fastpath;sys_wait4;do_wait;schedule 120709
bash;entry_SYSCALL_64_fastpath;sys_wait4;do_wait;schedule 699320 us

更多例子

examples:
    ./offcputime             # trace off-CPU stack time until Ctrl-C
    ./offcputime 5           # trace for 5 seconds only
    ./offcputime -f 5        # 5 seconds, and output in folded format
    ./offcputime -m 1000     # trace only events that last more than 1000 usec
    ./offcputime -M 10000    # trace only events that last less than 10000 usec
    ./offcputime -p 185      # only trace threads for PID 185
    ./offcputime -t 188      # only trace thread 188
    ./offcputime -u          # only trace user threads (no kernel)
    ./offcputime -k          # only trace kernel threads (no user)
    ./offcputime -U          # only show user space stacks (no kernel)
    ./offcputime -K          # only show kernel space stacks (no user)