kprobe not appearing in output, only kretprobe (in prospective kprobe_netlink example)

[chrispsommers]

I created a fork and new feature branch at https://github.com/chrispsommers/libbpf-bootstrap/tree/kprobe_netlink-example#kprobe_netlink. I added example kprobe_netlink to trace netlink messages. The tracing output only shows the kretprobe messages for some reason. Any advice? You can clone this and build using the normal recipes if you care to try it. See below, thanks:

sudo ./kprobe_netlink 
libbpf: loading object 'kprobe_netlink_bpf' from buffer
libbpf: elf: section(2) kprobe/netlink_unicast, size 240, link 0, flags 6, type=1
libbpf: sec 'kprobe/netlink_unicast': found program 'netlink_unicast' at insn offset 0 (0 bytes), code size 30 insns (240 bytes)
libbpf: elf: section(3) kretprobe/netlink_unicast, size 280, link 0, flags 6, type=1
libbpf: sec 'kretprobe/netlink_unicast': found program 'netlink_unicast_exit' at insn offset 0 (0 bytes), code size 35 insns (280 bytes)
libbpf: elf: section(4) kprobe/netlink_broadcast, size 232, link 0, flags 6, type=1
libbpf: sec 'kprobe/netlink_broadcast': found program 'netlink_broadcast' at insn offset 0 (0 bytes), code size 29 insns (232 bytes)
libbpf: elf: section(5) kretprobe/netlink_broadcast, size 248, link 0, flags 6, type=1
libbpf: sec 'kretprobe/netlink_broadcast': found program 'netlink_broadcast_exit' at insn offset 0 (0 bytes), code size 31 insns (248 bytes)
libbpf: elf: section(6) license, size 13, link 0, flags 3, type=1
libbpf: license of kprobe_netlink_bpf is Dual BSD/GPL
libbpf: elf: section(7) .rodata.str1.1, size 201, link 0, flags 32, type=1
libbpf: elf: skipping unrecognized data section(7) .rodata.str1.1
libbpf: elf: section(8) .BTF, size 1641, link 0, flags 0, type=1
libbpf: elf: section(9) .BTF.ext, size 684, link 0, flags 0, type=1
libbpf: elf: section(10) .symtab, size 240, link 14, flags 0, type=2
libbpf: looking for externs among 10 symbols...
libbpf: collected 0 externs total
libbpf: loading kernel BTF '/sys/kernel/btf/vmlinux': 0
libbpf: sec 'kprobe/netlink_unicast': found 1 CO-RE relocations
libbpf: prog 'netlink_unicast': relo #0: kind <byte_off> (0), spec is [2] struct pt_regs.dx (0:12 @ offset 96)
libbpf: CO-RE relocating [0] struct pt_regs: found target candidate [221] struct pt_regs in [vmlinux]
libbpf: prog 'netlink_unicast': relo #0: matching candidate #0 [221] struct pt_regs.dx (0:12 @ offset 96)
libbpf: prog 'netlink_unicast': relo #0: patched insn #0 (LDX/ST/STX) off 96 -> 96
libbpf: sec 'kretprobe/netlink_unicast': found 1 CO-RE relocations
libbpf: prog 'netlink_unicast_exit': relo #0: kind <byte_off> (0), spec is [2] struct pt_regs.ax (0:10 @ offset 80)
libbpf: prog 'netlink_unicast_exit': relo #0: matching candidate #0 [221] struct pt_regs.ax (0:10 @ offset 80)
libbpf: prog 'netlink_unicast_exit': relo #0: patched insn #0 (LDX/ST/STX) off 80 -> 80
libbpf: sec 'kprobe/netlink_broadcast': found 1 CO-RE relocations
libbpf: prog 'netlink_broadcast': relo #0: kind <byte_off> (0), spec is [2] struct pt_regs.dx (0:12 @ offset 96)
libbpf: prog 'netlink_broadcast': relo #0: matching candidate #0 [221] struct pt_regs.dx (0:12 @ offset 96)
libbpf: prog 'netlink_broadcast': relo #0: patched insn #0 (LDX/ST/STX) off 96 -> 96
libbpf: sec 'kretprobe/netlink_broadcast': found 1 CO-RE relocations
libbpf: prog 'netlink_broadcast_exit': relo #0: kind <byte_off> (0), spec is [2] struct pt_regs.ax (0:10 @ offset 80)
libbpf: prog 'netlink_broadcast_exit': relo #0: matching candidate #0 [221] struct pt_regs.ax (0:10 @ offset 80)
libbpf: prog 'netlink_broadcast_exit': relo #0: patched insn #0 (LDX/ST/STX) off 80 -> 80
Successfully started! Please run `sudo cat /sys/kernel/debug/tracing/trace_pipe` to see output of the BPF programs.
........

Trace output:
$ sudo cat /sys/kernel/debug/tracing/trace_pipe
sudo-31063 [010] d... 90928.229245: bpf_trace_printk: KPROBE netlink_unicast_exit EXIT: pid = 31063, ret = 36

        sudo-31063   [010] d... 90928.229252: bpf_trace_printk: KPROBE netlink_unicast_exit EXIT: pid = 31063, ret = 176

        sudo-31063   [010] d... 90928.229352: bpf_trace_printk: KPROBE netlink_unicast_exit EXIT: pid = 31063, ret = 36

        sudo-31063   [010] d... 90928.229354: bpf_trace_printk: KPROBE netlink_unicast_exit EXIT: pid = 31063, ret = 136

[chenhengqi]

Change:

bpf_printk("KPROBE netlink_unicast pid = %d, portid=%08x\n", pid, portid);

to:

bpf_printk("KPROBE netlink_unicast pid = %d, portid=%x\n", pid, portid);

Currently, only a small subset of format specifiers are supported by BPF.

[chrispsommers]

Awesome, that fixed it. Thanks! Given that there was no error while running the "broken" code, should I file another issue? Or was there some diagnostic output I overlooked?

[chenhengqi]

bpf_printk is a wrapper around bpf helper bpf_trace_printk.

The behavior and supported specifiers of bpf_trace_printk are well documented.

You can print return value of bpf_printk to debug the problem.