Easier trace_pipe handling

[brendangregg]

Some code I'm commonly using (Python):

b = BPF(...)

# open trace pipe
try:
    trace = open("/sys/kernel/debug/tracing/trace_pipe", "r")
except:
    print >> sys.stderr, "ERROR: opening trace_pipe"
    exit(1)

# format output
while 1:
    try:
        line = trace.readline().rstrip()
    except KeyboardInterrupt:
        pass; exit()

This could be improved. Eg:

b = BPF(...)

# format output
while 1:
    try:
        line = b.read_trace_pipe()
    except KeyboardInterrupt:
        pass; exit()

BPF can provide a read_trace_pipe() function to perform a readline() and rstrip() from the trace_pipe. It can open the trace_pipe if it wasn't already open (therefore the trace_pipe isn't opened unless the user explicitly uses the BPF.read_trace_pipe() function).

Perhaps the implementation could also use trace instances (see Instances in https://github.com/torvalds/linux/blob/master/Documentation/trace/ftrace.txt), so that multiple concurrent users would use separate trace_pipes.

[drzaeus77]

Just looked into trace instances, and it seems that only high level events are supported, not fine-grained kprobe_events. Bummer.

[brendangregg]

kprobes do work with instances, although I couldn't find an example. Here's how:

session1# mkdir /sys/kernel/debug/tracing/instances/foo
session1# echo 'p:my do_sys_open' > /sys/kernel/debug/tracing/kprobe_events 
session1# echo 1 > /sys/kernel/debug/tracing/instances/foo/events/kprobes/my/enable
session1# cat /sys/kernel/debug/tracing/trace_pipe
[no output]

No output is seen from the gloabal trace_pipe. Note that the kprobe is created in the global kprobe_events file, then enabled in the instance's enable file.

Then:

session2# cat /sys/kernel/debug/tracing/instances/foo/trace_pipe 
           snmpd-1618  [002] d... 29184684.385913: my: (do_sys_open+0x0/0x210)
           snmpd-1618  [002] d... 29184684.386089: my: (do_sys_open+0x0/0x210)
           snmpd-1618  [002] d... 29184684.386337: my: (do_sys_open+0x0/0x210)
           snmpd-1618  [002] d... 29184684.386395: my: (do_sys_open+0x0/0x210)
           snmpd-1618  [002] d... 29184684.386447: my: (do_sys_open+0x0/0x210)
           snmpd-1618  [002] d... 29184684.386497: my: (do_sys_open+0x0/0x210)
[...]

These kprobe events only appear in the instance's trace_pipe (session2, not session1).

If you enable the probe from the global /sys/kernel/debug/tracing/events... then events only appear in the global /sys/kernel/debug/tracing/trace_pipe.

Remember to rm the instances/foo directory after use. :)

I would imagine we'd create an "instances/bcc$PID" directory for the sessions.

[drzaeus77]

I dug into this a little bit more, and while kprobes do work fine with instances, printk inside of a kprobe does not work fine. There is only 1 global trace printk buffer.

[brendangregg]

Ah, damn, but good to know. We can still have read_trace_pipe() and trace_print() for this issue (and read_trace_fields() from #149), and have a separate issue later for concurrent users, once kernel support exists.

[drzaeus77]

I think #156 should address this issue now. Please close the ticket if you agree.

[brendangregg]

Thanks, #156 should so I'll close this ticket (I'll add some comments to #156).