examples/tracing: lbr.py trace cond branches executed by syscalls

[lorenzocarrozzo]

This script uses the Last Branch Record (LBR) buffer to trace conditional branches executed by syscalls. The script takes a snapshot of the LBR and displays the to/ from address to the user. This can be useful if you want are trying to trace the execution path of a syscall which is returning an error. If this script is not too niche I would be happy to submit it as a tool as well.

[yonghong-song]

It seems a useful example. But I tried and already found a few errors:

[~/tmp]$ sudo python3.6 lbr.py -t clone                                                                                                                
/virtual/main.c:21:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed                                                              
   21 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);                                                                                      
      |                               ^                                                                                                                                   
/virtual/main.c:34:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed                                                              
   34 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);                                                                                      
      |                               ^                                                                                                                                   
2 warnings generated.                                                                                                                                                     
Warning: Setting field pid on perf_event_attr that isn't part of the ctype - pid won't make it to perf_event_open                                                         

Tracing logical branches... Hit Ctrl-C to end.                                                                                                                            

i  | T/F  | Addresses                            |                                                                                                                        
-------------------------------------------------|                                                                                                                        
0  | From | trace_call_bpf+0x76/0x240            |                                                                                                                        
   |---------------------------------------------|                                                                                                                        
   | To   | trace_call_bpf+0xb6/0x240            |                                                                                                                        
-------------------------------------------------| 
...
Traceback (most recent call last):
  File "lbr.py", line 238, in <module>
    print_snapshot()
  File "lbr.py", line 194, in print_snapshot
    to_addrs.append(addrs[1])
IndexError: list index out of range
[~/tmp]$ sudo python3.6 lbr.py -k clone                            
/virtual/main.c:21:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed
   21 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);
      |                               ^
/virtual/main.c:34:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed
   34 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);
      |                               ^
2 warnings generated.
Warning: Setting field pid on perf_event_attr that isn't part of the ctype - pid won't make it to perf_event_open

Tracing logical branches... Hit Ctrl-C to end.

Traceback (most recent call last):
  File "lbr.py", line 238, in <module>
    print_snapshot()
  File "lbr.py", line 186, in print_snapshot
    total_entries = int(msg)
ValueError: invalid literal for int() with base 10: b'enqueue_task_fair+0x109a/0x1670 --> enqueue_task_fair+0x4ac/0x1670'
[~/tmp]$

I didn't try other commands. Could you take a look?

[lorenzocarrozzo]

It seems a useful example. But I tried and already found a few errors:

[~/tmp]$ sudo python3.6 lbr.py -t clone                                                                                                                
/virtual/main.c:21:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed                                                              
   21 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);                                                                                      
      |                               ^                                                                                                                                   
/virtual/main.c:34:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed                                                              
   34 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);                                                                                      
      |                               ^                                                                                                                                   
2 warnings generated.                                                                                                                                                     
Warning: Setting field pid on perf_event_attr that isn't part of the ctype - pid won't make it to perf_event_open                                                         

Tracing logical branches... Hit Ctrl-C to end.                                                                                                                            

i  | T/F  | Addresses                            |                                                                                                                        
-------------------------------------------------|                                                                                                                        
0  | From | trace_call_bpf+0x76/0x240            |                                                                                                                        
   |---------------------------------------------|                                                                                                                        
   | To   | trace_call_bpf+0xb6/0x240            |                                                                                                                        
-------------------------------------------------| 
...
Traceback (most recent call last):
  File "lbr.py", line 238, in <module>
    print_snapshot()
  File "lbr.py", line 194, in print_snapshot
    to_addrs.append(addrs[1])
IndexError: list index out of range
[~/tmp]$ sudo python3.6 lbr.py -k clone                            
/virtual/main.c:21:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed
   21 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);
      |                               ^
/virtual/main.c:34:31: warning: only %d %u %x %ld %lu %lx %lld %llu %llx %p %s conversion specifiers allowed
   34 |             bpf_trace_printk("%pS --> %pS", entries[i].from, entries[i].to);
      |                               ^
2 warnings generated.
Warning: Setting field pid on perf_event_attr that isn't part of the ctype - pid won't make it to perf_event_open

Tracing logical branches... Hit Ctrl-C to end.

Traceback (most recent call last):
  File "lbr.py", line 238, in <module>
    print_snapshot()
  File "lbr.py", line 186, in print_snapshot
    total_entries = int(msg)
ValueError: invalid literal for int() with base 10: b'enqueue_task_fair+0x109a/0x1670 --> enqueue_task_fair+0x4ac/0x1670'
[~/tmp]$

I didn't try other commands. Could you take a look?

Apologies these crashes were to do with me failing to take into account the concurrency of the bpf trace_pipe. I’ve added some tags to the output of the lbr script to allow it to distinguish between the origin of the messages it reads from the bpf trace_pipe.

[lorenzocarrozzo]

As for the warning about using %pS I was wondering if you know if there is a specific reason as to why it is not included in BCC’s allowed conversion specifiers? I can change it to %p to get rid of the warning but this ultimately makes the tools output less useful.

[lorenzocarrozzo]

Also the warning about the pid field is due to me being unable to use Perf.perf_event_open() to setup my perf event as its arguments are too strict. Specifically I need access to the attr.sample_type and attr.branch_sample_type. Would it be best if I suggest adding these options in another patch?

[yonghong-song]

As for the warning about using %pS I was wondering if you know if there is a specific reason as to why it is not included in BCC’s allowed conversion specifiers? I can change it to %p to get rid of the warning but this ultimately makes the tools output less useful.

The supported kernel bpf_trace_printk format can be found in the following kernel file https://github.com/torvalds/linux/blob/master/kernel/bpf/helpers.c#L815 The function is bpf_bprintf_prepare().

Could you help improve bcc to cover more supported strings? The related file is b_frontend_action.cc, function checkFormatSpecifiers.

Currently, warning does not impact functionality, but we still want to warn issues for incorrect format other users won't have idea why a particular bpf_trace_printk won't print anything.

[yonghong-song]

Also the warning about the pid field is due to me being unable to use Perf.perf_event_open() to setup my perf event as its arguments are too strict. Specifically I need access to the attr.sample_type and attr.branch_sample_type. Would it be best if I suggest adding these options in another patch?

Yes, please. A separate patch to add sample_type/branch_sample_type in perf_event_open() API looks okay to me.

[lorenzocarrozzo]

I have submitted two new patches which should fix the warnings. When they are merged I will update the script to use the new API.

[lorenzocarrozzo]

I have updated the script to use Perf.perf_custom_event_open() Also Ive opened a separate patch to fix the pid warning as the custom perf event function did not fully fix the issue