Helper function bpf_trace_printk
This helper prints messages to the trace log of the kernel.
Definition
Copyright (c) 2015 The Libbpf Authors. All rights reserved.
Returns The number of bytes written to the buffer, or a negative error in case of failure.
static long (* const bpf_trace_printk)(const char *fmt, __u32 fmt_size, ...) = (void *) 6;
Usage
This helper is a "printk()-like" facility for debugging. It prints a message defined by format fmt
(of size fmt_size
) to file /sys/kernel/tracing/trace
from TraceFS, if available. It can take up to three additional u64
arguments (as an eBPF helpers, the total number of arguments is limited to five).
Warning
A commonly made mistake is to call bpf_trace_printk
with a literal string like
char *fmt = "some log";
bpf_trace_printk(fmt, 9);
The compiler will place such a literal string in a ELF section meant for the heap, which does not exist in eBPF programs. Rater the fmt
should be defined as static const
static const char fmt[] = "some log";
bpf_trace_printk(fmt, sizeof(fmt))
which will result in the format being stack allocated. A good alternative would be to use the bpf_printk
macro provided by the libbpf's bpf_helpers.h file which does this step for you. bpf_printk("some log");
Trace output
Each time the helper is called, it appends a line to the trace. Lines are discarded while /sys/kernel/tracing/trace
is open, use /sys/kernel/tracing/trace_pipe
to avoid this. The format of the trace is customizable, and the exact output one will get depends on the options set in /sys/kernel/tracing/trace_options
(see also the README
file under the same directory). However, it usually defaults to something like:
telnet-470 [001] .N.. 419421.045894: 0x00000001: <formatted msg>
In the above:
telnet
is the name of the current task. 470
is the PID of the current task. 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 instruction pointer register. <formatted msg>
is the message formatted with fmt
.
String format
The conversion specifiers supported by fmt
are similar, but more limited than for printk()
. They are:
%d
,%i
- Signed integer decimal%u
- Unsigned integer decimal%x
- Integer hexadecimal%ld
,%li
- Signed long decimal%lu
- Unsigned long decimal%lx
- Long hexadecimal%lld
,%lli
- Long long decimal%llu
- Unsigned long long decimal%llx
- Long long hexadecimal%p
- Pointer as decimal%s
- String
No modifier (size of field, padding with zeroes, etc.) is available, and the helper will return -EINVAL
(but print nothing) if it encounters an unknown specifier.
The above is true for pre v5.13 kernels. Since then the following changes were made:
%%
- Produces a percent char%
- Modifiers such as
%03d
or%+d
no longer cause-EINVAL
but are ignored. - Uppercase
%x
(%X
,%lX
,%llX
) now prints the hexadecimal output but with uppercase chars instead. %pK
- Kernel pointer which should be hidden from unprivileged users%px
- Pointer as hexadecimal%pB
- Pointer to a symbol, prints the name with offsets and should be used when printing stack backtraces%pi4
,%pI4
- Pointer to an IPv4 address%pi6
,%pI6
- Pointer to an IPv6 address
Note
bpf_trace_printk()
is slow, and should only be used for debugging purposes. For this reason, a notice block (spanning several lines) is printed to kernel logs and states that the helper should not be used "for production use" the first time this helper is used (or more precisely, when trace_printk()
buffers are allocated). For passing values to user space, perf events should be preferred.
Program types
This helper call can be used in the following program types:
- BPF_PROG_TYPE_CGROUP_DEVICE
- BPF_PROG_TYPE_CGROUP_SKB
- BPF_PROG_TYPE_CGROUP_SOCK
- BPF_PROG_TYPE_CGROUP_SOCKOPT
- BPF_PROG_TYPE_CGROUP_SOCK_ADDR
- BPF_PROG_TYPE_CGROUP_SYSCTL
- BPF_PROG_TYPE_FLOW_DISSECTOR
- BPF_PROG_TYPE_KPROBE
- BPF_PROG_TYPE_LIRC_MODE2
- BPF_PROG_TYPE_LSM
- BPF_PROG_TYPE_LWT_IN
- BPF_PROG_TYPE_LWT_OUT
- BPF_PROG_TYPE_LWT_SEG6LOCAL
- BPF_PROG_TYPE_LWT_XMIT
- BPF_PROG_TYPE_PERF_EVENT
- BPF_PROG_TYPE_RAW_TRACEPOINT
- BPF_PROG_TYPE_RAW_TRACEPOINT_WRITABLE
- BPF_PROG_TYPE_SCHED_ACT
- BPF_PROG_TYPE_SCHED_CLS
- BPF_PROG_TYPE_SK_LOOKUP
- BPF_PROG_TYPE_SK_MSG
- BPF_PROG_TYPE_SK_REUSEPORT
- BPF_PROG_TYPE_SK_SKB
- BPF_PROG_TYPE_SOCKET_FILTER
- BPF_PROG_TYPE_SOCK_OPS
- BPF_PROG_TYPE_SYSCALL
- BPF_PROG_TYPE_TRACEPOINT
- BPF_PROG_TYPE_TRACING
- BPF_PROG_TYPE_XDP
Example
static const char fmt[] = "some log";
bpf_trace_printk(fmt, sizeof(fmt));
//
static const char fmt[] = "some int: %d";
bpf_trace_printk(fmt, sizeof(fmt), 123);
//
static const char fmt[] = "big number: %lld";
long long abc = 123456789;
bpf_trace_printk(fmt, sizeof(fmt), abc);