ply

/* a dynamic tracer for Linux */

$_ flexible

Type inference in combination with a compact C-like syntax means scripts can be written and edited in seconds, directly in your favorite shell. The language is heavily inspired by, though not nearly as powerful as, awk(1) and dtrace(1).

>< small

Designed with embedded systems in mind. Written in C, all ply needs to run is libc and a modern kernel with Linux BPF support. No external kernel modules, no LLVM, no python. Works on x86_64 and arm today, adding more architectures is easy.

<3 efficient

Data gathering and aggregation is done in the kernel using Linux BPF programs that are JIT compiled to native instructions on most common architectures. Thus, ply runs with very low overhead, allowing it to probe even the hottest code paths.

 "yeah yeah whatever, so what can I actually do with it?!"

- well I'm glad you asked, dear reader, here are a few examples

count syscalls, system-wide

#!/usr/sbin/ply

kprobe:SyS_*
{
    @syscalls[func()].count()
}

This probe will be attached to all functions whose name starts with SyS_, i.e. all syscalls. On each syscall, the probe will fire and index into the user-defined map @syscalls using the function func() as the key and bump a counter.

ply will compile the script, attach it to the matching probes and start collecting data. On exit, ply will dump the values of all user-defined maps.

wkz@wkz-x260:~$ sudo ./n-syscalls.ply
341 probes active
^Cde-activating probes

@syscalls:
sys_tgkill          	       1
sys_mprotect        	       1
sys_lseek           	       1
sys_readv           	       1
sys_rename          	       1
sys_statfs          	       1
sys_bind            	       2
sys_access          	       4
sys_fdatasync       	       5
sys_times           	       6
[REDACTED LINES]
sys_epoll_wait      	    7211
sys_ppoll           	    9836
sys_poll            	   13446
sys_futex           	   20034
sys_ioctl           	   23806
sys_recvmsg         	   23989
sys_write           	   24791
sys_read            	   32168

read(2) return distribution

#!/usr/sbin/ply

kretprobe:SyS_read
{
    @.quantize(retval());
}

This example shows a very simple script that instruments the return of the read(2) syscall and records the distribution of the return argument.

User-defined maps in ply always start with @. When writing small scripts, only using one map, it is common and convenient to simply call it @.

wkz@wkz-x260:~$ sudo ./read-dist.ply
1 probe active
^Cde-activating probes

@:

             < 0        8869 ┤███████           │
               0         565 ┤▌                 │
               1       13460 ┤██████████▋       │
    [   2,    3]        1915 ┤█▌                │
    [   4,    7]        1736 ┤█▍                │
    [   8,   15]       10054 ┤████████          │
    [  16,   31]        2583 ┤██                │
    [  32,   63]         769 ┤▋                 │
    [  64,  127]          55 ┤                  │
    [ 128,  255]           5 ┤                  │
    [ 256,  511]         202 ┤▏                 │
    [ 512,   1k)          27 ┤                  │
    [  1k,   2k)         157 ┤▏                 │
    [  2k,   4k)           4 ┤                  │
    [  4k,   8k)          20 ┤                  │
    [  8k,  16k)           6 ┤                  │
    [ 16k,  32k)          23 ┤                  │
    [ 32k,  64k)          20 ┤                  │

capture stack traces

#!/usr/sbin/ply

kprobe:i2c_transfer
{
    printf("%v\n", stack())
}

Sometimes it can be useful to know how a particular location is reached. kprobes can get the current stack trace via the stack() function. Using the format specifier %v tells ply to use the default format of the inferred type of the argument.

In this example, the stack trace is simply printed to stdout, but it can also be used as a map key in an aggregation. I.e. it is possible to do frequency counting based on how a function was reached.

root@chaos:~ $ ply ./i2c-stack.ply &
root@chaos:~ $ 1 probe active

root@chaos:~ $ hwclock -r

    i2c_transfer
    i2c_smbus_read_i2c_block_data+0x58
    ds1307_native_smbus_read_block_data+0x88
    ds1307_get_time+0x38
    __rtc_read_time+0x54
    rtc_read_time+0x3c
    rtc_dev_ioctl+0x318
    do_vfs_ioctl+0xa0
    sys_ioctl+0x44
    __sys_trace_return
Mon Feb 20 18:33:33 2017  0.000000 seconds
root@chaos:~ $ fg
ply ./i2c_stack.ply
^Cde-activating probes
root@chaos:~ $

opensnoop

#!/usr/sbin/ply

kprobe:SyS_open
{
    printf("%16s(%5d): %s\n",
           comm(), pid(), mem(arg(0), "128s"));
}

Every time a process calls open(2) print the calling process's comm, i.e. executable name, PID and the filename by extracting a 128-byte string from the address of the first argument using the mem() function.

wkz@wkz-x260:~$ sudo ./opensoop.ply
1 probe active
             ply(28836): /sys/kernel/debug/tracing/events/enable
 SimpleCacheWork( 5818): /home/wkz/.cache/google-chrome/Default/Cache/37586f4b9464a393_0
      irqbalance( 1083): /proc/interrupts
      irqbalance( 1083): /proc/stat
      irqbalance( 1083): /proc/irq/18/smp_affinity
      irqbalance( 1083): /proc/irq/126/smp_affinity
      irqbalance( 1083): /proc/irq/128/smp_affinity
      irqbalance( 1083): /proc/irq/122/smp_affinity
      irqbalance( 1083): /proc/irq/11/smp_affinity
      irqbalance( 1083): /proc/irq/124/smp_affinity
      irqbalance( 1083): /proc/irq/16/smp_affinity
      irqbalance( 1083): /proc/irq/1/smp_affinity
      irqbalance( 1083): /proc/irq/8/smp_affinity
      irqbalance( 1083): /proc/irq/9/smp_affinity
      irqbalance( 1083): /proc/irq/12/smp_affinity
      irqbalance( 1083): /proc/irq/120/smp_affinity
      irqbalance( 1083): /proc/irq/121/smp_affinity
 Chrome_IOThread( 5361): /dev/shm/.org.chromium.Chromium.59XkZF
 SimpleCacheWork( 5818): /home/wkz/.cache/google-chrome/Default/Cache/37586f4b9464a393_0
     Core Thread( 5368): /home/wkz/.config/spotify/Users/wkz-user/pending-messages.tmp
     Core Thread( 5368): /home/wkz/.config/spotify/Users/wkz-user/pending-messages.tmp
^Cde-activating probes