Updated man and examples with new probe syntax and command-line switches

README.md

@@ -65,6 +65,7 @@ Examples:
 
 Tools:
 
+- tools/[argdist](tools/argdist.py): Display function parameter values as a histogram or frequency count. [Examples](tools/argdist_example.txt).
 - tools/[bashreadline](tools/bashreadline.py): Print entered bash commands system wide. [Examples](tools/bashreadline_example.txt).
 - tools/[biolatency](tools/biolatency.py): Summarize block device I/O latency as a histogram. [Examples](tools/biolatency_example.txt).
 - tools/[biotop](tools/biotop.py): Top for disks: Summarize block device I/O by process. [Examples](tools/biotop_example.txt).
@@ -79,7 +80,6 @@ Tools:
 - tools/[filetop](tools/filetop.py): File reads and writes by filename and process. Top for files. [Examples](tools/filetop_example.txt).
 - tools/[funccount](tools/funccount.py): Count kernel function calls. [Examples](tools/funccount_example.txt).
 - tools/[funclatency](tools/funclatency.py): Time kernel functions and show their latency distribution. [Examples](tools/funclatency_example.txt).
-- tools/[gentrace](tools/gentrace.py): Trace function parameter values as a histogram or raw data. [Examples](tools/gentrace_examples.txt).
 - tools/[gethostlatency](tools/gethostlatency.py): Show latency for getaddrinfo/gethostbyname[2] calls. [Examples](tools/gethostlatency_example.txt).
 - tools/[hardirqs](tools/hardirqs.py):  Measure hard IRQ (hard interrupt) event time. [Examples](tools/hardirqs_example.txt).
 - tools/[killsnoop](tools/killsnoop.py): Trace signals issued by the kill() syscall. [Examples](tools/killsnoop_example.txt).

man/man8/argdist.8

-.TH gentrace 8  "2016-02-11" "USER COMMANDS"
+.TH argdist 8  "2016-02-11" "USER COMMANDS"
 .SH NAME
-gentrace \- Trace a function and display a histogram or summary of its parameter values. Uses Linux eBPF/bcc.
+argdist \- Trace a function and display a histogram or frequency count of its parameter values. Uses Linux eBPF/bcc.
 .SH SYNOPSIS
-.B gentrace [-h] [-p PID] [-z STRING_SIZE] [-i INTERVAL] [-c COUNT] specifier [specifier ...]
+.B argdist [-h] [-p PID] [-z STRING_SIZE] [-i INTERVAL] [-n COUNT] [-H specifier [specifier ...]] [-C specifier [specifier ...]]
 .SH DESCRIPTION
-gentrace attaches to function entry and exit points, collects specified parameter
-values, and stores them in a histogram or a raw counting collection that counts
+argdist attaches to function entry and exit points, collects specified parameter
+values, and stores them in a histogram or a frequency collection that counts
 the number of times a parameter value occurred. It can also filter parameter
 values and instrument multiple entry points at once.
 
@@ -18,8 +18,7 @@ CONFIG_BPF and bcc.
 Print usage message.
 .TP
 \-p PID
-Trace only functions in the process PID. This filter will only apply to user-space
-functions. If you only provide kernel-space probes, the filter is ignored.
+Trace only functions in the process PID.
 .TP
 \-z STRING_SIZE
 When collecting string arguments (of type char*), collect up to STRING_SIZE 
@@ -28,88 +27,98 @@ characters. Longer strings will be truncated.
 -i INTERVAL
 Print the collected data every INTERVAL seconds. The default is 1 second.
 .TP
--c COUNT
+-n NUMBER
 Print the collected data COUNT times and then exit.
 .TP
-SPECIFIER
-One or more probe specifications that instruct gentrace which functions to
+-H SPECIFIER, -C SPECIFIER
+One or more probe specifications that instruct argdist which functions to
 probe, which parameters to collect, how to aggregate them, and whether to perform
 any filtering. See SPECIFIER SYNTAX below.
 .SH SPECIFIER SYNTAX
 The general specifier syntax is as follows:
 
-.B <raw|hist>[-ret]:[library]:function(signature)[:type:expr[:filter]]
+.B {p,r}:[library]:function(signature)[:type:expr[:filter]][;label]
 .TP
-Probe type \- "raw", "hist", "raw-ret", "hist-ret".
-Indicates where to place the probe and whether the probe should collect raw
-event information, or aggregate the collected values into a histogram. Raw 
+.B {p,r}
+Probe type \- "p" for function entry, "r" for function return;
+\-H for histogram collection, \-C for frequency count.
+Indicates where to place the probe and whether the probe should collect frequency
+count information, or aggregate the collected values into a histogram. Counting 
 probes will collect the number of times every parameter value was observed,
 whereas histogram probes will collect the parameter values into a histogram.
 Only integral types can be used with histogram probes; there is no such limitation
-for raw probes. Suffix with \-ret to indicate that the probe should be placed
-at function return. This probe can only use the pseudo-variable @retval, which
+for counting probes. Return probes can only use the pseudo-variable $retval, which
 is an alias for the function's return value.
 .TP
+.B [library]
 Library containing the probe.
 Specify the full path to the .so or executable file where the function to probe
 resides. Alternatively, you can specify just the lib name: for example, "c"
 refers to libc. If no library name is specified, the kernel is assumed.
 .TP
+.B function(signature)
 The function to probe, and its signature.
 The function name must match exactly for the probe to be placed. The signature,
 on the other hand, is only required if you plan to collect parameter values 
 based on that signature. For example, if you only want to collect the first
 parameter, you don't have to specify the rest of the parameters in the signature.
 .TP
+.B [type]
 The type of the expression to capture.
 This is the type of the keys in the histogram or raw event collection that are
 collected by the probes.
 .TP
+.B [expr]
 The expression to capture.
 These are the values that are assigned to the histogram or raw event collection.
 You may use the parameters directly, or valid C expressions that involve the
 parameters, such as "size % 10".
 .TP
-A filter applied to the captured data.
+.B [filter]
+The filter applied to the captured data.
 Only parameter values that pass the filter will be collected. This is any valid
 C expression that refers to the parameter values, such as "fd == 1 && length > 16".
+.TP
+.B [label]
+The label that will be displayed when printing the probed values. By default,
+this is the probe specifier. 
 .SH EXAMPLES
 .TP
 Print a histogram of allocation sizes passed to kmalloc:
 #
-.B gentrace.py 'hist::__kmalloc(u64 size):u64:size'
+.B argdist.py -H 'p::__kmalloc(u64 size):u64:size'
 .TP
-Print a raw count of how many times process 1005 called malloc with an allocation size of 16 bytes:
+Print a count of how many times process 1005 called malloc with an allocation size of 16 bytes:
 #
-.B gentrace.py -p 1005 'raw:c:malloc(size_t size):size_t:size:size==16'
+.B argdist.py -p 1005 -C 'p:c:malloc(size_t size):size_t:size:size==16'
 .TP
 Snoop on all strings returned by gets():
 #
-.B gentrace.py 'raw-ret:c:gets():char*:@retval'
+.B argdist.py -C 'r:c:gets():char*:$retval'
 .TP
-Print raw counts of how many times writes were issued to a particular file descriptor number, in process 1005:
+Print frequency counts of how many times writes were issued to a particular file descriptor number, in process 1005:
 #
-.B gentrace.py -p 1005 'raw:c:write(int fd):int:fd'
+.B argdist.py -p 1005 -C 'p:c:write(int fd):int:fd'
 .TP
 Print a histogram of error codes returned by read() in process 1005:
 #
-.B gentrace.py -p 1005 'hist-ret:c:read()'
+.B argdist.py -p 1005 -H 'r:c:read()'
 .TP
 Print a histogram of buffer sizes passed to write() across all processes, where the file descriptor was 1 (STDOUT):
 #
-.B gentrace.py 'hist:c:write(int fd, const void *buf, size_t count):size_t:count:fd==1'
+.B argdist.py -H 'p:c:write(int fd, const void *buf, size_t count):size_t:count:fd==1'
 .TP
-Count fork() calls in libc across all processes:
+Count fork() calls in libc across all processes, grouped by pid:
 #
-.B gentrace.py 'raw:c:fork'
+.B argdist.py -C 'p:c:fork():int:$PID;fork per process'
 .TP
 Print histograms of sleep() and nanosleep() parameter values:
 #
-.B gentrace.py 'hist:c:sleep(u32 seconds):u32:seconds' 'hist:c:nanosleep(struct timespec { time_t tv_sec; long tv_nsec; } *req):long:req->tv_nsec'
+.B argdist.py -H 'p:c:sleep(u32 seconds):u32:seconds' -H 'p:c:nanosleep(struct timespec { time_t tv_sec; long tv_nsec; } *req):long:req->tv_nsec'
 .TP
 Spy on writes to STDOUT performed by process 2780, up to a string size of 120 characters:
 #
-.B gentrace.py -p 2780 -z 120 'raw:c:write(int fd, char* buf, size_t len):char*:buf:fd==1'
+.B argdist.py -p 2780 -z 120 -C 'p:c:write(int fd, char* buf, size_t len):char*:buf:fd==1'
 .SH SOURCE
 This is from bcc.
 .IP

tools/argdist.py

@@ -28,6 +28,14 @@ int PROBENAME(struct pt_regs *ctx SIGNATURE)
 }
 """
         next_probe_index = 0
+        aliases = { "$PID": "bpf_get_current_pid_tgid()" }
+
+        def _substitute_aliases(self, expr):
+                if expr is None:
+                        return expr
+                for alias, subst in Specifier.aliases.items():
+                        expr = expr.replace(alias, subst)
+                return expr
 
         def __init__(self, type, specifier, pid):
                 self.raw_spec = specifier 
@@ -66,6 +74,8 @@ int PROBENAME(struct pt_regs *ctx SIGNATURE)
                 if self.filter is not None:
                         self.filter = self.filter.replace("$retval",
                                 "(%s)ctx->ax" % self.expr_type)
+                self.expr = self._substitute_aliases(self.expr)
+                self.filter = self._substitute_aliases(self.filter)
                 self.pid = pid
                 self.probe_func_name = "%s_probe%d" % \
                         (self.function, Specifier.next_probe_index)

tools/argdist_example.txt → tools/argdist_examples.txt

-Demonstrations of gentrace.
+Demonstrations of argdist.
 
 
-gentrace probes functions you specify and collects parameter values into a
-histogram or a counting table. This can be used to understand the distribution
+argdist probes functions you specify and collects parameter values into a
+histogram or a frequency count. This can be used to understand the distribution
 of values a certain parameter takes, filter and print interesting parameters
-without attaching a debugger, and getting general execution statistics on
+without attaching a debugger, and obtain general execution statistics on
 various functions.
 
 For example, suppose you want to find what allocation sizes are common in
 your application:
 
-# ./gentrace.py -p 2420 "raw:c:malloc(size_t size):size_t:size"
+# ./argdist.py -p 2420 -C 'p:c:malloc(size_t size):size_t:size'
 [01:42:29]
-raw:c:malloc(size_t size):size_t:size
+p:c:malloc(size_t size):size_t:size
         COUNT      EVENT
 [01:42:30]
-raw:c:malloc(size_t size):size_t:size
+p:c:malloc(size_t size):size_t:size
         COUNT      EVENT
 [01:42:31]
-raw:c:malloc(size_t size):size_t:size
+p:c:malloc(size_t size):size_t:size
         COUNT      EVENT
         1          size = 16
 [01:42:32]
-raw:c:malloc(size_t size):size_t:size
+p:c:malloc(size_t size):size_t:size
         COUNT      EVENT
         2          size = 16
 [01:42:33]
-raw:c:malloc(size_t size):size_t:size
+p:c:malloc(size_t size):size_t:size
         COUNT      EVENT
         3          size = 16
 [01:42:34]
-raw:c:malloc(size_t size):size_t:size
+p:c:malloc(size_t size):size_t:size
         COUNT      EVENT
         4          size = 16
 ^C
@@ -43,9 +43,9 @@ probed and its value was 16, repeatedly.
 Now, suppose you wanted a histogram of buffer sizes passed to the write()
 function across the system:
 
-# ./gentrace.py "hist:c:write(int fd, void *buf, size_t len):size_t:len"
+# ./argdist.py -H 'p:c:write(int fd, void *buf, size_t len):size_t:len'
 [01:45:22]
-hist:c:write(int fd, void *buf, size_t len):size_t:len
+p:c:write(int fd, void *buf, size_t len):size_t:len
      len                 : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 2        |*************                           |
@@ -54,7 +54,7 @@ hist:c:write(int fd, void *buf, size_t len):size_t:len
         16 -> 31         : 0        |                                        |
         32 -> 63         : 6        |****************************************|
 [01:45:23]
-hist:c:write(int fd, void *buf, size_t len):size_t:len
+p:c:write(int fd, void *buf, size_t len):size_t:len
      len                 : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 11       |***************                         |
@@ -64,7 +64,7 @@ hist:c:write(int fd, void *buf, size_t len):size_t:len
         32 -> 63         : 28       |****************************************|
         64 -> 127        : 12       |*****************                       |
 [01:45:24]
-hist:c:write(int fd, void *buf, size_t len):size_t:len
+p:c:write(int fd, void *buf, size_t len):size_t:len
      len                 : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 21       |****************                        |
@@ -81,9 +81,9 @@ bytes, medium writes of 32-63 bytes, and larger writes of 64-127 bytes.
 But these are writes across the board -- what if you wanted to focus on writes
 to STDOUT?
 
-# ./gentrace.py "hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1" 
+# ./argdist.py -H 'p:c:write(int fd, void *buf, size_t len):size_t:len:fd==1'
 [01:47:17]
-hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
+p:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
      len                 : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 0        |                                        |
@@ -92,7 +92,7 @@ hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
         16 -> 31         : 0        |                                        |
         32 -> 63         : 1        |****************************************|
 [01:47:18]
-hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
+p:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
      len                 : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 0        |                                        |
@@ -102,7 +102,7 @@ hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
         32 -> 63         : 3        |********************                    |
         64 -> 127        : 6        |****************************************|
 [01:47:19]
-hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
+p:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
      len                 : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 0        |                                        |
@@ -116,20 +116,20 @@ hist:c:write(int fd, void *buf, size_t len):size_t:len:fd==1
 The "fd==1" part is a filter that is applied to every invocation of write().
 Only if the filter condition is true, the value is recorded.
 
-You can also use gentrace to trace kernel functions. For example, suppose you
+You can also use argdist to trace kernel functions. For example, suppose you
 wanted a histogram of kernel allocation (kmalloc) sizes across the system,
 printed twice with 3 second intervals:
 
-# ./gentrace.py -i 3 -c 2 "hist::__kmalloc(size_t size):size_t:size"
+# ./argdist.py -i 3 -n 2 -H 'p::__kmalloc(size_t size):size_t:size'
 [01:50:00]
-hist::__kmalloc(size_t size):size_t:size
+p::__kmalloc(size_t size):size_t:size
      size                : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 0        |                                        |
          4 -> 7          : 0        |                                        |
          8 -> 15         : 6        |****************************************|
 [01:50:03]
-hist::__kmalloc(size_t size):size_t:size
+p::__kmalloc(size_t size):size_t:size
      size                : count     distribution
          0 -> 1          : 0        |                                        |
          2 -> 3          : 0        |                                        |
@@ -143,9 +143,9 @@ hist::__kmalloc(size_t size):size_t:size
 Occasionally, numeric information isn't enough and you want to capture strings.
 What are the strings printed by puts() across the system?
 
-# ./gentrace.py -i 10 -c 1 "raw:c:puts(char *str):char*:str"
+# ./argdist.py -i 10 -n 1 -C 'p:c:puts(char *str):char*:str'
 [01:53:54]
-raw:c:puts(char *str):char*:str
+p:c:puts(char *str):char*:str
         COUNT      EVENT
         2          str = Press ENTER to start.
 
@@ -153,22 +153,23 @@ It looks like the message "Press ENTER to start." was printed twice during the
 10 seconds we were tracing.
 
 What about reads? You could trace gets() across the system and print the 
-strings input by the user:
+strings input by the user (note how "r" is used instead of "p" to attach a
+probe to the function's return):
 
-# ./gentrace.py -i 10 -c 1 "raw-ret:c:gets():char*:@retval"
+# ./argdist.py -i 10 -n 1 -C 'r:c:gets():char*:$retval:$retval!=0'
 [02:12:23]
-raw-ret:c:gets():char*:@retval
+r:c:gets():char*:$retval:$retval!=0
         COUNT      EVENT
         1          (char*)ctx->ax = hi there
-        1          (char*)ctx->ax = sasha
-        1          (char*)ctx->ax = hello
+        3          (char*)ctx->ax = sasha
+        8          (char*)ctx->ax = hello
 
 Similarly, we could get a histogram of the error codes returned by read():
 
-# ./gentrace.py -i 10 -c 1 "hist-ret:c:read()"
+# ./argdist.py -i 10 -c 1 -H 'r:c:read()'
 [02:15:36]
-hist-ret:c:read()
-     (int)ctx->ax        : count     distribution
+r:c:read()
+     retval              : count     distribution
          0 -> 1          : 29       |****************************************|
          2 -> 3          : 11       |***************                         |
          4 -> 7          : 0        |                                        |
@@ -182,18 +183,35 @@ hist-ret:c:read()
       1024 -> 2047       : 0        |                                        |
       2048 -> 4095       : 2        |**                                      |
 
+Here's a final example that finds how many write() system calls are performed
+by each process on the system:
+
+# argdist.py -C 'p:c:write():int:$PID;write per process' -n 2
+[06:47:18]
+write by process
+        COUNT      EVENT
+        3          bpf_get_current_pid_tgid() = 8889
+        7          bpf_get_current_pid_tgid() = 7615
+        7          bpf_get_current_pid_tgid() = 2480
+[06:47:19]
+write by process
+        COUNT      EVENT
+        9          bpf_get_current_pid_tgid() = 8889
+        23         bpf_get_current_pid_tgid() = 7615
+        23         bpf_get_current_pid_tgid() = 2480
+
+As you see, the $PID alias is expanded to the BPF function bpf_get_current_pid_tgid(),
+which returns the current process' pid.
+
 
 USAGE message:
 
-# ./gentrace.py -h
-usage: gentrace.py [-h] [-p PID] [-z STRING_SIZE] [-i INTERVAL] [-c COUNT]
-                   specifier [specifier ...]
+usage: argdist.py [-h] [-p PID] [-z STRING_SIZE] [-i INTERVAL] [-n COUNT]
+                  [-H [HISTSPECIFIER [HISTSPECIFIER ...]]]
+                  [-C [COUNTSPECIFIER [COUNTSPECIFIER ...]]] [-v]
 
 Trace a function and display a summary of its parameter values.
 
-positional arguments:
-  specifier             the probe specifiers (see examples below)
-
 optional arguments:
   -h, --help            show this help message and exit
   -p PID, --pid PID     id of the process to trace (optional)
@@ -201,55 +219,65 @@ optional arguments:
                         maximum string size to read from char* arguments
   -i INTERVAL, --interval INTERVAL
                         output interval, in seconds
-  -c COUNT, --count COUNT
+  -n COUNT, --number COUNT
                         number of outputs
+  -H [HISTSPECIFIER [HISTSPECIFIER ...]], --histogram [HISTSPECIFIER [HISTSPECIFIER ...]]
+                        probe specifier to capture histogram of (see examples
+                        below)
+  -C [COUNTSPECIFIER [COUNTSPECIFIER ...]], --count [COUNTSPECIFIER [COUNTSPECIFIER ...]]
+                        probe specifier to capture count of (see examples
+                        below)
+  -v, --verbose         print resulting BPF program code before executing
 
 Probe specifier syntax:
-        <raw|hist>[-ret]:[library]:function(signature)[:type:expr[:filter]]
+        {p,r}:[library]:function(signature)[:type:expr[:filter]][;label]
 Where:
-        <raw|hist> -- collect raw data or a histogram of values
-        ret        -- probe at function exit, only @retval is accessible
+        p,r        -- probe at function entry or at function exit
+                      in exit probes, only $retval is accessible
         library    -- the library that contains the function
                       (leave empty for kernel functions)
         function   -- the function name to trace
         signature  -- the function's parameters, as in the C header
         type       -- the type of the expression to collect
         expr       -- the expression to collect
-        filter     -- a filter that is applied to collected values
+        filter     -- the filter that is applied to collected values
+        label      -- the label for this probe in the resulting output
 
 EXAMPLES:
 
-gentrace.py "hist::__kmalloc(u64 size):u64:size"
+argdist.py -H 'p::__kmalloc(u64 size):u64:size'
         Print a histogram of allocation sizes passed to kmalloc
 
-gentrace.py -p 1005 "raw:c:malloc(size_t size):size_t:size:size==16"
-        Print a raw count of how many times process 1005 called malloc with
-        an allocation size of 16 bytes
+argdist.py -p 1005 -C 'p:c:malloc(size_t size):size_t:size:size==16'
+        Print a frequency count of how many times process 1005 called malloc
+        with an allocation size of 16 bytes
 
-gentrace.py "raw-ret:c:gets():char*:@retval"
+argdist.py -C 'r:c:gets():char*:$retval;snooped strings'
         Snoop on all strings returned by gets()
 
-gentrace.py -p 1005 "raw:c:write(int fd):int:fd"
-        Print raw counts of how many times writes were issued to a particular
-        file descriptor number, in process 1005
+argdist.py -p 1005 -C 'p:c:write(int fd):int:fd'
+        Print frequency counts of how many times writes were issued to a
+        particular file descriptor number, in process 1005
 
-gentrace.py -p 1005 "hist-ret:c:read()"
+argdist.py -p 1005 -H 'r:c:read()'
         Print a histogram of error codes returned by read() in process 1005
 
-gentrace.py "hist:c:write(int fd, const void *buf, size_t count):size_t:count:fd==1"
+argdist.py -H \
+        'p:c:write(int fd, const void *buf, size_t count):size_t:count:fd==1'
         Print a histogram of buffer sizes passed to write() across all
         processes, where the file descriptor was 1 (STDOUT)
 
-gentrace.py "raw:c:fork"
+argdist.py -C 'p:c:fork();fork calls'
         Count fork() calls in libc across all processes
         Can also use funccount.py, which is easier and more flexible
 
-gentrace.py \
-        "hist:c:sleep(u32 seconds):u32:seconds" \
-        "hist:c:nanosleep(struct timespec { time_t tv_sec; long tv_nsec; } *req):long:req->tv_nsec"
+argdist.py \
+        -H 'p:c:sleep(u32 seconds):u32:seconds' \
+        -H 'p:c:nanosleep(struct timespec { time_t tv_sec; long tv_nsec; } *req):long:req->tv_nsec'
         Print histograms of sleep() and nanosleep() parameter values
 
-gentrace.py -p 2780 -z 120 "raw:c:write(int fd, char* buf, size_t len):char*:buf:fd==1"
+argdist.py -p 2780 -z 120 \
+        -C 'p:c:write(int fd, char* buf, size_t len):char*:buf:fd==1'
         Spy on writes to STDOUT performed by process 2780, up to a string size
         of 120 characters