pwru

pwru copied to clipboard

Fix #239

Support tracing XDP

Add an option --filter-trace-xdp to trace all XDP progs on host by fentry-ing on the progs, like the way tracing tc-bpf https://github.com/Asphaltt/pwru/commit/2347755900fffe100ab9eebaa180bb9f482df6fb.

The diff from tracing tc-bpf:

1. Not support to filter mark.
2. No mark in meta output.
3. No proto in meta output.
4. Not support --output-skb.

Example with --filter-trace-xdp --filter-trace-tc:

./pwru --filter-trace-xdp --filter-trace-tc --output-limit-lines 10 --filter-func 'xxx' --output-meta --output-tuple icmp
2024/03/04 14:26:47 Listening for events..
               SKB    CPU          PROCESS                     FUNC
0xffffbb8cc062cc28      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ed4596aa00      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffffbb8cc062cc28      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ed4596ba00      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffffbb8cc062cc28      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ed4596a700      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffffbb8cc062cc28      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ed4596b500      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffffbb8cc062cc28      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ed4596b400      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
2024/03/04 14:26:52 Printed 10 events, exiting program..

Thanks! I found it may be a technical obstacle for us to trace a frame's lifetime, it seems no way to link an xdp_buff to an skb: the "skb addr" is different, we can't know which skb an xdp_buff has turned to.

There is a possible approach to link an xdp_buff and an sk_buff: xdp_buff->data_hard_start and sk_buff->head.

I'll do a POC to confirm it later.

It seems great to use xdp_buff->data_hard_start and sk_buff->head.

root@leon-vm ~/P/l/pwru (feature/xdp)# ./pwru --filter-trace-xdp --filter-trace-tc --output-limit-lines 10 --filter-func 'xxx' --output-meta --output-tuple icmp
2024/03/05 12:31:01 Attaching kprobes (via kprobe-multi)...
0 [_________________________________________________________________________________________________________________________________________________] ?% ? p/s
2024/03/05 12:31:01 Attached (ignored 0)
2024/03/05 12:31:01 Listening for events..
               SKB    CPU          PROCESS                     FUNC
0xffff95ee12521000      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]               dummy(xdp) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0000 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
0xffff95ee12521000      7     [<empty>(0)]                dummy(tc) netns=4026531840 mark=0x0 iface=2(ens33) proto=0x0800 mtu=1500 len=98 192.168.241.1:0->192.168.241.128:0(icmp)
2024/03/05 12:31:03 Printed 10 events, exiting program..
2024/03/05 12:31:03 Detaching kprobes...
0 [_________________________________________________________________________________________________________________________________________________] ?% ? p/s
root@leon-vm ~/P/l/pwru (feature/xdp)# git diff
diff --git a/bpf/kprobe_pwru.c b/bpf/kprobe_pwru.c
index f60913c..7411d8a 100644
--- a/bpf/kprobe_pwru.c
+++ b/bpf/kprobe_pwru.c
@@ -391,7 +391,7 @@ int BPF_PROG(fentry_tc, struct sk_buff *skb) {
        if (!handle_everything(skb, ctx, &event))
                return BPF_OK;

-       event.skb_addr = (u64) skb;
+       event.skb_addr = (u64) BPF_CORE_READ(skb, head);
        event.addr = BPF_PROG_ADDR;
        event.type = EVENT_TYPE_TC;
        bpf_map_push_elem(&events, &event, BPF_EXIST);
@@ -488,7 +488,7 @@ int BPF_PROG(fentry_xdp, struct xdp_buff *xdp) {
        event.pid = bpf_get_current_pid_tgid() >> 32;
        event.ts = bpf_ktime_get_ns();
        event.cpu_id = bpf_get_smp_processor_id();
-       event.skb_addr = (u64) xdp;
+       event.skb_addr = (u64) BPF_CORE_READ(xdp, data_hard_start);
        event.addr = BPF_PROG_ADDR;
        event.type = EVENT_TYPE_XDP;
        bpf_map_push_elem(&events, &event, BPF_EXIST);

Let me apply this diff.

Thanks! I've just tried running, and got:

2024/03/17 16:59:32 failed to trace XDP progs: failed to trace bpf progs: failed to get entry function name: bpf program xdp_foo does not have BTF

Maybe we could ignore such progs instead of panic?

It seems great to use xdp_buff->data_hard_start and sk_buff->head.

Are you saying that both point to the same in the case XDP moves to the host (e.g., TC)?

OT: could you drop the last commit, and just do git rebase origin/main?

Are you saying that both point to the same in the case XDP moves to the host (e.g., TC)?

Yes. As the output in previous reply.

When to build xdp_buff from data: xdp_prepare_buff When to build skb from data: __finalize_skb_around

OT: could you drop the last commit, and just do git rebase origin/main?

Oh, sorry for my bad "merge". I will rebase it later.

When to build xdp_buff from data: xdp_prepare_buff When to build skb from data: __finalize_skb_around

With these changes --trace-skb starts tracking some unrelated packets (see at the very end in after.log). I've traced NodePort BPF traffic on Kind with ./pwru --filter-track-skb --filter-trace-tc --output-meta --output-tuple 'port 30828'.

• after.log - with PR changes
• before.log - before PR changes

With these changes --trace-skb starts tracking some unrelated packets (see at the very end in after.log).

It seems it does not remove the skb addr from skb_addresses bpf map.

Did it log Warn: kfree_skbmem not found, pwru is likely to mismatch skb due to lack of skb lifetime management when to run with --filter-track-skb? If it logged it, it would track the cloned/copied skbs without removing them from skb_addresses bpf map.

I'd like to fix this code logic bug in https://github.com/cilium/pwru/pull/340.

Did it log Warn: kfree_skbmem not found, pwru is likely to mismatch skb due to lack of skb lifetime management when to run with --filter-track-skb? If it logged it, it would track the cloned/copied skbs without removing them from skb_addresses bpf map.

Noup, it didn't log. Shall I give it a go #340?

Shall I give it a go https://github.com/cilium/pwru/pull/340?

Sure.

Indeed, adding #340 to this branch resolved the last traces hiccup. Thanks! However, I still miss some traces when running this PR with #340. E.g., tcp_v4_conn_request (before.txt, after.txt). Any idea regarding this?

@Asphaltt could you rebase your PR?