Re: Issues with bpf_trace_printk

[Daniel Borkmann <daniel@iogearbox.net>]

On 08/28/2017 07:20 PM, Zvi Effron wrote:
> Hello,
>
> I'm having an issue where bpf_trace_printk seems to always print 0 for
> values. I'm running the following xdp program:
>
>
> #include <uapi/linux/bpf.h>
>
> static int (*bpf_trace_printk)(const char *fmt, int fmt_size, ...) =
> (void *) BPF_FUNC_trace_printk;
>
> int xdp(struct xdp_md *ctx) {
>      char format_string[] = "Data start: %x\tData end: %x\n";
>      bpf_trace_printk(format_string, sizeof(format_string), ctx->data,
> ctx->data_end);
>
>      {
>          char format_string[] = "Constant: %x\n";
>          bpf_trace_printk(format_string, sizeof(format_string), 1);
>      }
>
>      if (ctx->data == 0) {
>          char format_string[] = "Data starts at offset 0";
>          bpf_trace_printk(format_string, sizeof(format_string));
>      }
>      if (ctx->data_end == 0) {
>          char format_string[] = "Data ends at offset 0";
>          bpf_trace_printk(format_string, sizeof(format_string));
>      }
>      return XDP_PASS;
> }
>
> char __attribute__((section("license"), used)) license[] = "GPL";
>
>
> and I get the following output in /sys/kernel/debug/tracing/trace_pipe
>
>
>              sshd-4824  [000] ..s1 67372.673714: : Data start: 0 Data end: 0
>              sshd-4824  [000] ..s1 67372.673720: : Constant: 0
>            <idle>-0     [000] ..s. 67372.675062: : Data start: 0 Data end: 0
>            <idle>-0     [000] .Ns. 67372.675090: : Constant: 0
>            <idle>-0     [000] .Ns. 67372.675116: : Data start: 0 Data end: 0
>            <idle>-0     [000] .Ns. 67372.675117: : Constant: 0
>            <idle>-0     [000] .Ns. 67372.675129: : Data start: 0 Data end: 0
>            <idle>-0     [000] .Ns. 67372.675130: : Constant: 0
>            <idle>-0     [000] .Ns. 67372.675136: : Data start: 0 Data end: 0
>            <idle>-0     [000] .Ns. 67372.675137: : Constant: 0
>            <idle>-0     [000] .Ns. 67372.675142: : Data start: 0 Data end: 0
>            <idle>-0     [000] .Ns. 67372.675143: : Constant: 0
>                ip-6458  [000] ..s. 67372.676083: : Data start: 0 Data end: 0
>                ip-6458  [000] ..s. 67372.676084: : Constant: 0
>                ip-6458  [000] ..s. 67372.676093: : Data start: 0 Data end: 0
>                ip-6458  [000] ..s. 67372.676094: : Constant: 0
>
>
> It looks like ctx->data and ctx->data_end are not 0, because the calls
> to bpf_trace_printk in those ifs aren't being called, and the constant
> is definitely not 0.
>
> What might I be missing or doing incorrectly?

Are you on 32bit? Could you dump the verifier output?

Thanks,
Daniel