Fix tracing tc-bpf with --filter-track-skb-by-stackid

[Asphaltt]

For tracing tc-bpf (same for XDP), it is able to get FP from r10 to track skb by stack ID.

@jschwinger233 could you give me a hand to test this PR by pwru --filter-trace-tc --filter-track-skb-by-stackid?

[jschwinger233]

Sorry but what's the problem you are fixing? 😬 Just went through issues but failed to find one, though I do remember there was an issue regarding --trace-tc + --bpf-helpers. 😭

Running pwru --filter-track-bpf-helpers --output-caller --filter-trace-tc 'src port 19233 and tcp[tcpflags]=tcp-syn' from main looks good to me...

[Asphaltt]

Sorry. Should I raise an issue?

The issue was avoided by 5455e74.

Then, this PR is to fix the issue actually.

[jschwinger233]

Now I understand thank you!

…

On Fri, 8 Nov 2024 at 1:03 PM, Leon Hwang ***@***.***> wrote: Sorry. Should I raise an issue? The issue was avoided by 5455e74 <5455e74> . Then, this PR is to fix the issue actually. — Reply to this email directly, view it on GitHub <#452 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABRDGKBERKBYQFYCZKI4NLLZ7RA2TAVCNFSM6AAAAABRLD26OWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDINRTG43TENRXHA> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[jschwinger233]

I'm afraid it doesn't work 😬

I used two different approaches to verify, both gave negative result.

Let me show the intuitive way:

diff --git a/bpf/kprobe_pwru.c b/bpf/kprobe_pwru.c
index a69f020..1674982 100644
--- a/bpf/kprobe_pwru.c
+++ b/bpf/kprobe_pwru.c
@@ -88,6 +88,7 @@ struct event_t {
        u64 param_second;
        u64 param_third;
        u32 cpu_id;
+
 } __attribute__((packed));
 
 #define MAX_QUEUE_ENTRIES 10000
@@ -508,6 +509,8 @@ cont:
        event->ts = bpf_ktime_get_ns();
        event->cpu_id = bpf_get_smp_processor_id();
 
+       event->print_stack_id = tracked_by;
+
        return true;
 }
 
diff --git a/internal/pwru/output.go b/internal/pwru/output.go
index 254b906..d3b128a 100644
--- a/internal/pwru/output.go
+++ b/internal/pwru/output.go
@@ -435,6 +435,7 @@ func (o *output) Print(event *Event) {
                fmt.Fprintf(o.writer, "%s", getShinfoData(event, o))
        }
 
+       fmt.Fprintf(o.writer, " %d", event.PrintStackId)
        fmt.Fprintln(o.writer)
 }

This patch unconditionally prints tracked_by variable from kernel to show the track reason.

With this PR + patch above, pwru --filter-track-skb-by-stackid --output-caller --filter-trace-tc 'src port 19233 and tcp[tcpflags]=tcp-syn' outputs:

0xffff91c8bbe772e8 2   ~bin/curl:192104 4026533015 0        ~010d98928d56:13 0x0800 1500  60    10.244.1.216:19233->10.244.3.176:8080(tcp) enqueue_to_backlog      netif_rx_internal 4
0xffff91c8bbe772e8 2   ~bin/curl:192104 4026533015 0        ~010d98928d56:13 0x0800 1500  60    10.244.1.216:19233->10.244.3.176:8080(tcp) __netif_receive_skb     process_backlog 4
0xffff91c8bbe772e8 2   curl:192104      4026533015 0        ~010d98928d56:13 0x0800 1500  60    10.244.1.216:19233->10.244.3.176:8080(tcp) __netif_receive_skb_one_core __netif_receive_skb 4
0xffff91c8bbe772e8 2   curl:192104      4026533015 0        ~010d98928d56:13 0x0800 1500  74    10.244.1.216:19233->10.244.3.176:8080(tcp) bpf_prog_a73bb86d02975a6f_cil_from_container[bpf](tc) __per_cpu_start 1
0xffff91c8bbe772e8 2   curl:192104      4026533015 0        ~010d98928d56:13 0x0800 1500  74    10.244.1.216:19233->10.244.3.176:8080(tcp) skb_ensure_writable                                   bpf_skb_pull_data 4
0xffff91c8bbe772e8 2   curl:192104      4026533015 0        ~010d98928d56:13 0x0800 1500  74    10.244.1.216:19233->10.244.3.176:8080(tcp) skb_ensure_writable                                   bpf_skb_pull_data 4
0xffff91c8bbe772e8 2   curl:192104      4026533015 81903e00 ~010d98928d56:13 0x0800 1500  60    10.244.1.216:19233->10.244.3.176:8080(tcp) ip_rcv                                                __netif_receive_skb_one_core 4

Have a look at the last colume of each line, which shows track reason of each event. The tc event still uses TRACKED_BY_FILTER (1) instead of TRACKED_BY_STACKID (4), demonstrating that get_stackid(is_kprobe=false) didn't unwind stack properly.

[Asphaltt]

get_stackid(is_kprobe=false) didn't unwind stack properly.

Bad news.

But, why doesn't work expectedly?

Then, I write a simple demo to disasm

static __always_inline u64
get_tracing_fp(void)
{
    u64 fp;

    /* get frame pointer */
    asm volatile ("%[fp] = r10" : [fp] "+r"(fp) :);
    return fp;
}

It shows:

; lbr.c:27:5 asm volatile ("%[fp] = r10" : [fp] "+r"(fp) :);
0xffffffffc03ebc34: 48 89 ea            movq    %rbp, %rdx

And the stack layout at the time of executing get_tracing_fp() should be:

+-------+
|  ...  | callers stack
|       |
|  rip  | caller's rip
|  rip  | tgt prog's rip
|  rbp  | tgt prog's caller's rbp
+- - - -+ trampoline's rbp
|  ...  |
|       |
|  rip  | trampoline's rip
|  rbp  | trampoline's rbp
+- - - -+ fentry_tc's rbp   <-- fp
|  ...  |
|       |
|       |
|-------| rsp

Next, %[fp] = r10 should get fentry_tc's rbp.

Therefore, it should work expectedly.

What are we missing here?

[Asphaltt]

@jschwinger233 can you bpf_printk() the unwinding FPs to compare FPs between kprobe and fentry_tc?