7

While running some examples from samples/bpf I noticed that bpf_printk output is prepended with some extra information, e.g. :

telnet-470   [001] .N.. 419421.045894: 0x00000001: BPF command: 2

BPF command: 2 is actual string passed to bpf_printk in the bpf program, but what is the rest? I assume this comes from kernel's JIT ?

Where can I look closer what those bits mean? Thanks.

pchaigno
  • 11,313
  • 2
  • 29
  • 54
Mark
  • 6,052
  • 8
  • 61
  • 129

1 Answers1

9

In your example:

telnet-470   [001] .N.. 419421.045894: 0x00000001: BPF command: 2
  • telnet is your current task's name.
  • 470 is your current task's PID.
  • 001 is the CPU number on which the task is running.
  • In .N.., each character refers to a set of options (whether irqs are enabled, scheduling options, whether hard/softirqs are running, level of preempt_disabled respectively). N means that TIF_NEED_RESCHED and PREEMPT_NEED_RESCHED are set.
  • 419421.045894 is a timestamp.
  • 0x00000001 is a fake value used by BPF for the ip register.
  • BPF command: 2 is your message.

Sources

The bpf_trace_printk helper calls trace_printk, whose format is detailed in the documentation for ftrace (Output format section). The fake ip value is commented in the original commit for the bpf_trace_printk helper.

As Qeole mentioned below, this format had nothing to do with the JIT compiler (or the eBPF infrastructure for that matter) and eBPF helpers don't need to be JIT compiled as they're already compiled as part of the kernel's source code.

pchaigno
  • 11,313
  • 2
  • 29
  • 54
  • 2
    Great answer! Regarding the question, I'd just clarify that JIT has nothing to do here. `bpf_trace_printk()` is a helper, so it's not JITted anyway (instead it's compiled as part of the kernel, and called from the eBPF program, whether it's interpreted or JITted). @pchaignon You mind if I reuse the details you provide for the doc about helpers I'm working on? – Qeole Dec 20 '17 at 22:45
  • @Qeole Sure! No problem. – pchaigno Dec 21 '17 at 08:13
  • Thank you for detailed explanation. – Mark Dec 21 '17 at 16:06
  • Is it possible to disable `ftrace` globally? Also, I read that `bpf_trace_printk()` produces output in `/sys/kernel/` I'm seeing the output of on console as well as in `/sys/kernel/debug/tracing/trace_pipe` but I also see it on the console. How do I limit it _only_ in sysfs? – Mark Jan 23 '18 at 13:59