Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Support tracing XDP #339

Merged
merged 5 commits into from
Jul 7, 2024
Merged

Support tracing XDP #339

merged 5 commits into from
Jul 7, 2024

Conversation

Asphaltt
Copy link
Contributor

@Asphaltt Asphaltt commented Mar 4, 2024

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
Asphaltt@2347755.

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..

@Asphaltt Asphaltt requested a review from a team as a code owner March 4, 2024 14:58
@Asphaltt Asphaltt requested review from brb and removed request for a team March 4, 2024 14:58
@jschwinger233
Copy link
Member

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.

@Asphaltt
Copy link
Contributor Author

Asphaltt commented Mar 5, 2024

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.

@Asphaltt
Copy link
Contributor Author

Asphaltt commented Mar 5, 2024

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.

@Asphaltt Asphaltt force-pushed the feature/xdp branch 2 times, most recently from 5ec35e9 to 7b97571 Compare March 10, 2024 03:56
@brb
Copy link
Member

brb commented Mar 17, 2024

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?

@brb
Copy link
Member

brb commented Mar 22, 2024

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?

@Asphaltt
Copy link
Contributor Author

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.

@brb
Copy link
Member

brb commented Apr 5, 2024

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'.

@Asphaltt
Copy link
Contributor Author

Asphaltt commented Apr 6, 2024

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 #340.

@brb
Copy link
Member

brb commented Apr 6, 2024

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?

@Asphaltt
Copy link
Contributor Author

Asphaltt commented Apr 6, 2024

Shall I give it a go #340?

Sure.

@brb
Copy link
Member

brb commented Apr 8, 2024

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?

@brb
Copy link
Member

brb commented Jun 17, 2024

@Asphaltt could you rebase your PR?

Copy link
Member

@brb brb left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Amazing! Could you rebase the PR? Once done, I will merge and do a new release.

internal/pwru/tc_tracer.go Show resolved Hide resolved
Asphaltt added 5 commits July 7, 2024 13:59
In bpf verifier, it denies that FENTRY/FEXIT cannot trace
BTF-not-annotated bpf progs. Or, an error "FENTRY/FEXIT program can only be attached to another program annotated with BTF" occurs.

Signed-off-by: Leon Hwang <[email protected]>
It's to trace XDP progs in future commits.

Signed-off-by: Leon Hwang <[email protected]>
Add an option --filter-trace-xdp to trace all XDP progs on host by
fentry-ing on the progs, like the way of tracing tc-bpf
2347755.

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.

Signed-off-by: Leon Hwang <[email protected]>
As we know, the hard start of packet data is same between `struct
sk_buff` and `struct xdp_buff`. So, we can track skb by it, and output
it as skb address.

Signed-off-by: Leon Hwang <[email protected]>
Address comments in PR cilium#340.

Signed-off-by: Leon Hwang <[email protected]>
@brb brb merged commit 438ea99 into cilium:main Jul 7, 2024
6 checks passed
jschwinger233 added a commit to jschwinger233/pwru that referenced this pull request Jul 10, 2024
cilium#339 changed how pwru collects
skb_addr, now it holds the value of skb->head instead of &skb.

This patch renames value name `skb_addr` to `skb_head`, as well as map
name `skb_addresses` to `skb_heads`.

Signed-off-by: gray <[email protected]>
jschwinger233 added a commit to jschwinger233/pwru that referenced this pull request Jul 10, 2024
After cilium#339, skb_addresses (now
skb_heads) map uses skb->head as key rather than &skb. Kprobe prog on
veth_convert_skb_to_xdp_buff should be adjusted to that change.

Signed-off-by: gray <[email protected]>
brb pushed a commit that referenced this pull request Jul 10, 2024
#339 changed how pwru collects
skb_addr, now it holds the value of skb->head instead of &skb.

This patch renames value name `skb_addr` to `skb_head`, as well as map
name `skb_addresses` to `skb_heads`.

Signed-off-by: gray <[email protected]>
brb pushed a commit that referenced this pull request Jul 10, 2024
After #339, skb_addresses (now
skb_heads) map uses skb->head as key rather than &skb. Kprobe prog on
veth_convert_skb_to_xdp_buff should be adjusted to that change.

Signed-off-by: gray <[email protected]>
jschwinger233 added a commit to jschwinger233/pwru that referenced this pull request Jul 12, 2024
cilium#391 allows --track-skb to track new
skb on veth, it relies on a map lookup to decide whether to track or
not:

```
SEC("kprobe/veth_convert_skb_to_xdp_buff")
int kprobe_veth_convert_skb_to_xdp_buff(struct pt_regs *ctx) {
[...]
	u64 skb_head = (u64) BPF_CORE_READ(skb, head);
	if (bpf_map_lookup_elem(&skb_heads, &skb_head)) {
[...]
	}
	return BPF_OK;
}
```

However, when --track-skb-by-stackid is used along with --track-skb, the
tracked skbs have risks not being recorded in skb_heads map.

This is because:
1. cilium#384 no more updates skb_heads
map when track reason is "by_stackid".
2. cilium#339 changes --track-skb from
   tracking &skb to tracking skb->head.

So imagine an skb whose original skb->head = 0xa, whose value is
updated to 0xb after a while. The first time pwru sees this skb,
skb_heads map will insert 0xa entry. However, after skb->head is set to
0xb, pwru sees the skb being tracked due to "by_stackid", we won't
insert 0xb entry into skb_heads map.

Then when the skb is on veth, we can't find an entry by looking up 0xb
from skb_heads map, ending up with losing track of veth skb again.

This patch fixes the issue by raising the priority of track_by_filter:
if an skb can be defined as tracked_by_filter and tracked_by_stackid,
use tracked_by_filter over tracked_by_stackid.

Another issue cilium#339 brings about is,
an skb can have multiple skb->head stored in skb_heads map during its
lifetime, but we only clean the latest value at
kprobe_skb_lifetime_termination. This issue is beyond this patch.

Signed-off-by: gray <[email protected]>
jschwinger233 added a commit to jschwinger233/pwru that referenced this pull request Jul 12, 2024
cilium#391 allows --track-skb to track new
skb on veth, it relies on a map lookup to decide whether to track or
not:

```
SEC("kprobe/veth_convert_skb_to_xdp_buff")
int kprobe_veth_convert_skb_to_xdp_buff(struct pt_regs *ctx) {
[...]
	u64 skb_head = (u64) BPF_CORE_READ(skb, head);
	if (bpf_map_lookup_elem(&skb_heads, &skb_head)) {
[...]
	}
	return BPF_OK;
}
```

However, when --track-skb-by-stackid is used along with --track-skb, the
tracked skbs have risks not being recorded in skb_heads map.

This is because:
1. cilium#384 no more updates skb_heads
map when track reason is "by_stackid".
2. cilium#339 changes --track-skb from
   using &skb to skb->head.

So imagine an skb whose original skb->head = 0xa, the value is updated
to 0xb after a while. The first time pwru sees this skb, skb_heads map
will insert 0xa entry, this is correct. However, after skb->head being
set to 0xb, pwru will verdict the skb of being tracked due to
"by_stackid", we end up not inserting 0xb entry into skb_heads map.

Then the skb reaches veth, pwru can't find an entry by looking up 0xb
from skb_heads map, we are losing track of veth skb again.

This patch fixes the issue by raising the priority of track_by_filter:
if an skb can be defined as both tracked_by_filter and
tracked_by_stackid, use tracked_by_filter over tracked_by_stackid.

Another issue cilium#339 brings about is,
an skb can have multiple skb->head stored in skb_heads map during its
lifetime, but we only clean the latest value at
kprobe_skb_lifetime_termination. This issue is beyond this patch.

Signed-off-by: gray <[email protected]>
jschwinger233 added a commit to jschwinger233/pwru that referenced this pull request Aug 6, 2024
cilium#339 changed how pwru tracks skb from
using &skb to skb->head for xdp tracing. We found it causing problems
such as:
1. An skb can have multiple different skb->head values during its
   lifetime, especically after (e.g. IPsec) encryption. Pwru now is
   likely to lose track of skb after encryption.
2. Some subtle issues like cilium#401. This
   is because some other tracking mechanism relies on &skb.

This commit brings back tracking &skb instead of skb->head. As for XDP
tracing, I'll introduce a new solution in the following patches.

Signed-off-by: gray <[email protected]>
brb pushed a commit that referenced this pull request Aug 30, 2024
#339 changed how pwru tracks skb from
using &skb to skb->head for xdp tracing. We found it causing problems
such as:
1. An skb can have multiple different skb->head values during its
   lifetime, especically after (e.g. IPsec) encryption. Pwru now is
   likely to lose track of skb after encryption.
2. Some subtle issues like #401. This
   is because some other tracking mechanism relies on &skb.

This commit brings back tracking &skb instead of skb->head. As for XDP
tracing, I'll introduce a new solution in the following patches.

Signed-off-by: gray <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add XDP support
3 participants