From 7f0a6f808488f32295f7fff6a030fd6c9e7a452e Mon Sep 17 00:00:00 2001 From: Andrew Birchall Date: Tue, 24 May 2016 01:44:41 -0700 Subject: [PATCH] Update documentation and man page for offcputime --- man/man8/offcputime.8 | 34 ++++++++++++++++++++-------------- tools/offcputime.py | 12 +++++++----- tools/offcputime_example.txt | 33 ++++++++++++++++++--------------- 3 files changed, 45 insertions(+), 34 deletions(-) diff --git a/man/man8/offcputime.8 b/man/man8/offcputime.8 index 0c6f75a8f262..7365a49a937f 100644 --- a/man/man8/offcputime.8 +++ b/man/man8/offcputime.8 @@ -4,17 +4,17 @@ offcputime \- Summarize off-CPU time by kernel stack trace. Uses Linux eBPF/bcc. .SH SYNOPSIS .B offcputime [\-h] [\-u] [\-p PID] [\-v] [\-f] [duration] .SH DESCRIPTION -This program shows kernel stack traces and task names that were blocked and -"off-CPU", and the total duration they were not running: their "off-CPU time". +This program shows stack traces and task names that were blocked and "off-CPU", +and the total duration they were not running: their "off-CPU time". It works by tracing when threads block and when they return to CPU, measuring -both the time they were off-CPU and the blocked kernel stack trace and the -task name. This data is summarized in the kernel using an eBPF map, and by -summing the off-CPU time by unique stack trace and task name. +both the time they were off-CPU and the blocked stack trace and the task name. +This data is summarized in the kernel using an eBPF map, and by summing the +off-CPU time by unique stack trace and task name. -The output summary will help you identify reasons why threads -were blocking, and quantify the time they were off-CPU. This spans all types -of blocking activity: disk I/O, network I/O, locks, page faults, involuntary -context switches, etc. +The output summary will help you identify reasons why threads were blocking, +and quantify the time they were off-CPU. This spans all types of blocking +activity: disk I/O, network I/O, locks, page faults, involuntary context +switches, etc. This is complementary to CPU profiling (e.g., CPU flame graphs) which shows the time spent on-CPU. This shows the time spent off-CPU, and the output, @@ -34,14 +34,20 @@ Print usage message. \-f Print output in folded stack format. .TP +\-p PID +Trace this process ID only (filtered in-kernel). +.TP \-u -Only trace user threads (not kernel threads). +Only trace user threads (no kernel threads). .TP -\-v -Show raw addresses (for non-folded output). +\-k +Only trace kernel threads (no user threads). .TP -\-p PID -Trace this process ID only (filtered in-kernel). +\-U +Show stacks from user space only (no kernel space stacks). +.TP +\-K +Show stacks from kernel space only (no user space stacks). .TP duration Duration to trace, in seconds. diff --git a/tools/offcputime.py b/tools/offcputime.py index 675a8025e530..185f2cf35ccb 100755 --- a/tools/offcputime.py +++ b/tools/offcputime.py @@ -42,23 +42,25 @@ def positive_nonzero_int(val): ./offcputime -p 185 # only trace threads for PID 185 ./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) """ parser = argparse.ArgumentParser( - description="Summarize off-CPU time by kernel stack trace", + description="Summarize off-CPU time by stack trace", formatter_class=argparse.RawDescriptionHelpFormatter, epilog=examples) thread_group = parser.add_mutually_exclusive_group() thread_group.add_argument("-p", "--pid", type=positive_int, help="trace this PID only") -thread_group.add_argument("-k", "--kernel-threads-only", action="store_true", - help="kernel threads only (no user threads)") thread_group.add_argument("-u", "--user-threads-only", action="store_true", help="user threads only (no kernel threads)") +thread_group.add_argument("-k", "--kernel-threads-only", action="store_true", + help="kernel threads only (no user threads)") stack_group = parser.add_mutually_exclusive_group() stack_group.add_argument("-U", "--user-stacks-only", action="store_true", - help="show stack from user space only (no kernel space stacks)") + help="show stacks from user space only (no kernel space stacks)") stack_group.add_argument("-K", "--kernel-stacks-only", action="store_true", - help="show stack from kernel space only (no user space stacks)") + help="show stacks from kernel space only (no user space stacks)") parser.add_argument("-f", "--folded", action="store_true", help="output folded format") parser.add_argument("--stack-storage-size", default=1024, diff --git a/tools/offcputime_example.txt b/tools/offcputime_example.txt index 18ce780588e7..ee0c6edb75d7 100644 --- a/tools/offcputime_example.txt +++ b/tools/offcputime_example.txt @@ -4,15 +4,16 @@ Demonstrations of offcputime, the Linux eBPF/bcc version. This program shows stack traces that were blocked, and the total duration they were blocked. It works by tracing when threads block and when they return to CPU, measuring both the time they were blocked (aka the "off-CPU time") and the -blocked kernel stack trace and the task name. This data is summarized in kernel -by summing the blocked time by unique stack trace and task name. +blocked stack trace and the task name. This data is summarized in kernel by +summing the blocked time by unique stack trace and task name. -Here is some example output. To explain what we are seeing: the very first -stack trace looks like a page fault (do_page_fault() etc) from the "chmod" -command, and in total was off-CPU for 13 microseconds. +Here is some example output. The -K option was used to only match kernel stacks. +To explain what we are seeing: the very first stack trace looks like a page +fault (do_page_fault() etc) from the "chmod" command, and in total was off-CPU +for 13 microseconds. # ./offcputime -K -Tracing off-CPU time (us) by kernel stack... Hit Ctrl-C to end. +Tracing off-CPU time (us) of all threads by kernel stack... Hit Ctrl-C to end. ^C schedule schedule_timeout @@ -587,7 +588,7 @@ Tracing off-CPU time (us) by kernel stack... Hit Ctrl-C to end. 81670888 The last few stack traces aren't very interesting, since they are threads that -are ofter blocked off-CPU waiting for work. +are often blocked off-CPU waiting for work. Do be somewhat careful with overhead: this is tracing scheduler functions, which can be called very frequently. While this uses in-kernel summaries for @@ -600,7 +601,7 @@ A -p option can be used to filter (in-kernel) on a single process ID. For example, only matching PID 26651, which is a running "dd" command: # ./offcputime -K -p 26651 -Tracing off-CPU time (us) by kernel stack... Hit Ctrl-C to end. +Tracing off-CPU time (us) of all threads by kernel stack... Hit Ctrl-C to end. ^C schedule schedule_timeout @@ -624,7 +625,7 @@ total of 2.4 seconds during tracing. A duration can be added, for example, tracing for 5 seconds only: # ./offcputime -K -p 26651 5 -Tracing off-CPU time (us) by kernel stack for 5 secs. +Tracing off-CPU time (us) of all threads by kernel stack for 5 secs. schedule schedule_timeout @@ -718,11 +719,11 @@ creating your "off-CPU time flame graphs". USAGE message: # ./offcputime -h -usage: offcputime.py [-h] [-p PID | -k | -u] [-U | -K] [-f] +usage: offcputime.py [-h] [-p PID | -k | -u] [-K | -U] [-f] [--stack-storage-size STACK_STORAGE_SIZE] [duration] -Summarize off-CPU time by kernel stack trace +Summarize off-CPU time by stack trace positional arguments: duration duration of trace, in seconds @@ -730,15 +731,15 @@ positional arguments: optional arguments: -h, --help show this help message and exit -p PID, --pid PID trace this PID only - -k, --kernel-threads-only - kernel threads only (no user threads) -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 stack from user space only (no kernel space + show stacks from user space only (no kernel space stacks) -K, --kernel-stacks-only - show stack from kernel space only (no user space + show stacks from kernel space only (no user space stacks) -f, --folded output folded format --stack-storage-size STACK_STORAGE_SIZE @@ -752,3 +753,5 @@ examples: ./offcputime -p 185 # only trace threads for PID 185 ./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)