|
| 1 | +# -*- fill-column: 76; -*- |
| 2 | +#+TITLE: Tutorial: Tracing03 - debug print |
| 3 | +#+OPTIONS: ^:nil |
| 4 | + |
| 5 | +In this lesson we will show how to print message from eBPF program |
| 6 | +into tracefs buffer. |
| 7 | + |
| 8 | +* Table of Contents :TOC: |
| 9 | +- [[#bpf-trace-printk][eBPF trace printk helper]] |
| 10 | +- [[#tracefs-pipe-reader][The tracefs pipe reader]] |
| 11 | +- [[#assignments][Assignments]] |
| 12 | + - [[#assignment-1-setting-up-your-test-lab][Assignment 1: Setting up your test lab]] |
| 13 | + - [[#assignment-2-bpf-trace-printk][Assignment 2: Run debug code]] |
| 14 | + |
| 15 | + |
| 16 | +* eBPF trace printk helper |
| 17 | + |
| 18 | +The bpf_trace_print helper function is very useful when debugging or |
| 19 | +when there's need for immediate feedback from the eBPF program. |
| 20 | + |
| 21 | +It offers limited trace_printk capability and basically stores message |
| 22 | +into the tracefs buffer. |
| 23 | + |
| 24 | +The bpf_trace_printk interface is: |
| 25 | + |
| 26 | +#+begin_example sh |
| 27 | +/* |
| 28 | + * Only limited trace_printk() conversion specifiers allowed: |
| 29 | + * %d %i %u %x %ld %li %lu %lx %lld %lli %llu %llx %p %s |
| 30 | + */ |
| 31 | +BPF_CALL_5(bpf_trace_printk, char *, fmt, u32, fmt_size, u64, arg1, |
| 32 | + u64, arg2, u64, arg3) |
| 33 | +#+end_example |
| 34 | + |
| 35 | +Because the above interface requires to put the size of the format |
| 36 | +string it's more convenient to use following macro, which allows |
| 37 | +alone string argument to be passed: |
| 38 | + |
| 39 | +#+begin_example sh |
| 40 | +#define bpf_printk(fmt, ...) \ |
| 41 | +({ \ |
| 42 | + char ____fmt[] = fmt; \ |
| 43 | + bpf_trace_printk(____fmt, sizeof(____fmt), \ |
| 44 | + ##__VA_ARGS__); \ |
| 45 | +}) |
| 46 | + |
| 47 | +SEC("xdp") |
| 48 | +int xdp_prog_simple(struct xdp_md *ctx) |
| 49 | +{ |
| 50 | + bpf_printk("..."); |
| 51 | + return XDP_PASS; |
| 52 | +} |
| 53 | +#+end_example |
| 54 | + |
| 55 | +* The tracefs pipe reader |
| 56 | + |
| 57 | +To retrieve the message printed by bpf_trace_printk, you can either |
| 58 | +read tracefs buffer directly: |
| 59 | + |
| 60 | +#+begin_example sh |
| 61 | +$ sudo cat /sys/kernel/debug/tracing/trace_pipe |
| 62 | +#+end_example |
| 63 | + |
| 64 | +Or you can use standard C file-reading/parsing code to get the data: |
| 65 | + |
| 66 | +#+begin_example sh |
| 67 | +stream = fopen(TRACEFS_PIPE, "r"); |
| 68 | + |
| 69 | +... |
| 70 | + |
| 71 | +while ((nread = getline(&line, &len, stream)) != -1) { |
| 72 | +#+end_example |
| 73 | + |
| 74 | +for more details please check on trace_read.c file. |
| 75 | + |
| 76 | +* Assignments |
| 77 | + |
| 78 | +** Assignment 1: Setting up your test lab |
| 79 | + |
| 80 | +In this lesson we will use the setup of the previous lesson: |
| 81 | +Basic02 - loading a program by name [[https://github.com/xdp-project/xdp-tutorial/tree/master/basic02-prog-by-name#assignment-2-add-xdp_abort-program]] |
| 82 | + |
| 83 | +Setup the environment: |
| 84 | + |
| 85 | +#+begin_example sh |
| 86 | +$ sudo ../testenv/testenv.sh setup --name veth-basic02 |
| 87 | +#+end_example |
| 88 | + |
| 89 | +Load XDP program from xdp_prog_kern.o that will print |
| 90 | +ethertnet header on every incomming packet: |
| 91 | + |
| 92 | +#+begin_example sh |
| 93 | +$ sudo ../basic02-prog-by-name/xdp_loader --dev veth-basic02 --force --progsec xdp |
| 94 | +#+end_example |
| 95 | + |
| 96 | +and make some packets: |
| 97 | + |
| 98 | +#+begin_example sh |
| 99 | +$ sudo ../testenv/testenv.sh enter --name veth-basic02 |
| 100 | +# ping fc00:dead:cafe:1::1 |
| 101 | +PING fc00:dead:cafe:1::1(fc00:dead:cafe:1::1) 56 data bytes |
| 102 | +#+end_example |
| 103 | + |
| 104 | +- Assignment 2: Run debug code |
| 105 | + |
| 106 | +#+begin_example sh |
| 107 | +bpf_printk("src: %llu, dst: %llu, proto: %u\n", |
| 108 | + ether_addr_to_u64(eth->h_source), |
| 109 | + ether_addr_to_u64(eth->h_dest), |
| 110 | + bpf_ntohs(eth->h_proto)); |
| 111 | +#+end_example |
| 112 | + |
| 113 | +You can monitor the message either via tracefs: |
| 114 | + |
| 115 | +#+begin_example sh |
| 116 | +$ sudo cat /sys/kernel/debug/tracing/trace_pipe |
| 117 | +ping-28172 [001] ..s1 155229.100016: 0: src: 99726513069783, dst: 63819112930922, proto: 56710 |
| 118 | +ping-28172 [001] ..s1 155230.124054: 0: src: 99726513069783, dst: 63819112930922, proto: 56710 |
| 119 | +ping-28172 [001] ..s1 155231.148018: 0: src: 99726513069783, dst: 63819112930922, proto: 56710 |
| 120 | +ping-28172 [001] ..s1 155232.172022: 0: src: 99726513069783, dst: 63819112930922, proto: 56710 |
| 121 | +#+end_example |
| 122 | + |
| 123 | +or with the trace_read application: |
| 124 | + |
| 125 | +#+begin_example sh |
| 126 | +$ sudo ./trace_read |
| 127 | +src: 5a:b3:63:62:de:d7 dst: 3a:b:b:8e:5e:6a proto: 56710 |
| 128 | +src: 5a:b3:63:62:de:d7 dst: 3a:b:b:8e:5e:6a proto: 56710 |
| 129 | +src: 5a:b3:63:62:de:d7 dst: 3a:b:b:8e:5e:6a proto: 56710 |
| 130 | +... |
| 131 | +#+end_example |
0 commit comments