[PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[Subash Abhinov Kasiviswanathan]

The following commits added support for printing the real address-
65875073eddd ("net: use %px to print skb address in trace_netif_receive_skb")
70713dddf3d2 ("net_sched: introduce tracepoint trace_qdisc_enqueue()")
851f36e40962 ("net_sched: use %px to print skb address in trace_qdisc_dequeue()")

However, tracing the packet traversal shows a mix of hashes and real
addresses. Pasting a sample trace for reference-

ping-14249   [002] .....  3424.046612: netif_rx_entry: dev=lo napi_id=0x3 queue_mapping=0
skbaddr=00000000dcbed83e vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800
ip_summed=0 hash=0x00000000 l4_hash=0 len=84 data_len=0 truesize=768 mac_header_valid=1
mac_header=-14 nr_frags=0 gso_size=0 gso_type=0x0
ping-14249   [002] .....  3424.046615: netif_rx: dev=lo skbaddr=ffffff888e5d1000 len=84

Switch the trace print formats to %p for all the events to have a
consistent format of printing the hashed addresses in all cases.

Signed-off-by: Sean Tranchetti <quic_stranche@quicinc.com>
Signed-off-by: Subash Abhinov Kasiviswanathan <quic_subashab@quicinc.com>
---
v1->v2: Switch to printing hashed addresses in all cases as mentioned by Eric.

 include/trace/events/net.h   | 2 +-
 include/trace/events/qdisc.h | 4 ++--
 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/include/trace/events/net.h b/include/trace/events/net.h
index 032b431..da611a7 100644
--- a/include/trace/events/net.h
+++ b/include/trace/events/net.h
@@ -136,7 +136,7 @@ DECLARE_EVENT_CLASS(net_dev_template,
 		__assign_str(name, skb->dev->name);
 	),
 
-	TP_printk("dev=%s skbaddr=%px len=%u",
+	TP_printk("dev=%s skbaddr=%p len=%u",
 		__get_str(name), __entry->skbaddr, __entry->len)
 )
 
diff --git a/include/trace/events/qdisc.h b/include/trace/events/qdisc.h
index 59c945b..a399592 100644
--- a/include/trace/events/qdisc.h
+++ b/include/trace/events/qdisc.h
@@ -41,7 +41,7 @@ TRACE_EVENT(qdisc_dequeue,
 		__entry->txq_state	= txq->state;
 	),
 
-	TP_printk("dequeue ifindex=%d qdisc handle=0x%X parent=0x%X txq_state=0x%lX packets=%d skbaddr=%px",
+	TP_printk("dequeue ifindex=%d qdisc handle=0x%X parent=0x%X txq_state=0x%lX packets=%d skbaddr=%p",
 		  __entry->ifindex, __entry->handle, __entry->parent,
 		  __entry->txq_state, __entry->packets, __entry->skbaddr )
 );
@@ -70,7 +70,7 @@ TRACE_EVENT(qdisc_enqueue,
 		__entry->parent	 = qdisc->parent;
 	),
 
-	TP_printk("enqueue ifindex=%d qdisc handle=0x%X parent=0x%X skbaddr=%px",
+	TP_printk("enqueue ifindex=%d qdisc handle=0x%X parent=0x%X skbaddr=%p",
 		  __entry->ifindex, __entry->handle, __entry->parent, __entry->skbaddr)
 );
 
-- 
2.7.4

Re: [PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[patchwork-bot+netdevbpf]

Hello:

This patch was applied to netdev/net-next.git (master)
by David S. Miller <davem@davemloft.net>:

On Fri, 24 Jun 2022 15:34:25 -0600 you wrote:
> The following commits added support for printing the real address-
> 65875073eddd ("net: use %px to print skb address in trace_netif_receive_skb")
> 70713dddf3d2 ("net_sched: introduce tracepoint trace_qdisc_enqueue()")
> 851f36e40962 ("net_sched: use %px to print skb address in trace_qdisc_dequeue()")
> 
> However, tracing the packet traversal shows a mix of hashes and real
> addresses. Pasting a sample trace for reference-
> 
> [...]

Here is the summary with links:
  - [net-next,v2] net: Print hashed skb addresses for all net and qdisc events
    https://git.kernel.org/netdev/net-next/c/6deb209dc6b0

You are awesome, thank you!
-- 
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html

Re: [PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[Cong Wang]

On Fri, Jun 24, 2022 at 03:34:25PM -0600, Subash Abhinov Kasiviswanathan wrote:
> The following commits added support for printing the real address-
> 65875073eddd ("net: use %px to print skb address in trace_netif_receive_skb")
> 70713dddf3d2 ("net_sched: introduce tracepoint trace_qdisc_enqueue()")
> 851f36e40962 ("net_sched: use %px to print skb address in trace_qdisc_dequeue()")
> 
> However, tracing the packet traversal shows a mix of hashes and real
> addresses. Pasting a sample trace for reference-
> 
> ping-14249   [002] .....  3424.046612: netif_rx_entry: dev=lo napi_id=0x3 queue_mapping=0
> skbaddr=00000000dcbed83e vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800
> ip_summed=0 hash=0x00000000 l4_hash=0 len=84 data_len=0 truesize=768 mac_header_valid=1
> mac_header=-14 nr_frags=0 gso_size=0 gso_type=0x0
> ping-14249   [002] .....  3424.046615: netif_rx: dev=lo skbaddr=ffffff888e5d1000 len=84
> 
> Switch the trace print formats to %p for all the events to have a
> consistent format of printing the hashed addresses in all cases.
> 

This is obscured...

What exactly is the inconsistency here? Both are apparently hex, from
user's point of view. The only difference is one is an apparently
invalid kernel address, the other is not. This difference only matters
when you try to dereference it, but I don't think you should do it here,
this is not a raw tracepoint at all. You can always use raw tracepoints
to dereference it without even bothering whatever we print.

Thanks.

Re: [PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[Subash Abhinov Kasiviswanathan (KS)]

On 6/27/2022 1:36 PM, Cong Wang wrote:
> On Fri, Jun 24, 2022 at 03:34:25PM -0600, Subash Abhinov Kasiviswanathan wrote:
>> The following commits added support for printing the real address-
>> 65875073eddd ("net: use %px to print skb address in trace_netif_receive_skb")
>> 70713dddf3d2 ("net_sched: introduce tracepoint trace_qdisc_enqueue()")
>> 851f36e40962 ("net_sched: use %px to print skb address in trace_qdisc_dequeue()")
>>
>> However, tracing the packet traversal shows a mix of hashes and real
>> addresses. Pasting a sample trace for reference-
>>
>> ping-14249   [002] .....  3424.046612: netif_rx_entry: dev=lo napi_id=0x3 queue_mapping=0
>> skbaddr=00000000dcbed83e vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800
>> ip_summed=0 hash=0x00000000 l4_hash=0 len=84 data_len=0 truesize=768 mac_header_valid=1
>> mac_header=-14 nr_frags=0 gso_size=0 gso_type=0x0
>> ping-14249   [002] .....  3424.046615: netif_rx: dev=lo skbaddr=ffffff888e5d1000 len=84
>>
>> Switch the trace print formats to %p for all the events to have a
>> consistent format of printing the hashed addresses in all cases.
>>
> 
> This is obscured...
> 
> What exactly is the inconsistency here? Both are apparently hex, from
> user's point of view. The only difference is one is an apparently
> invalid kernel address, the other is not. This difference only matters
> when you try to dereference it, but I don't think you should do it here,
> this is not a raw tracepoint at all. You can always use raw tracepoints
> to dereference it without even bothering whatever we print.
> 
> Thanks.

Matching skbs addresses (in a particular format) helps to track the 
packet traversal timings / delays in processing.

Re: [PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[Cong Wang]

On Mon, Jun 27, 2022 at 12:49 PM Subash Abhinov Kasiviswanathan (KS)
<quic_subashab@quicinc.com> wrote:
>
>
>
> On 6/27/2022 1:36 PM, Cong Wang wrote:
> > On Fri, Jun 24, 2022 at 03:34:25PM -0600, Subash Abhinov Kasiviswanathan wrote:
> >> The following commits added support for printing the real address-
> >> 65875073eddd ("net: use %px to print skb address in trace_netif_receive_skb")
> >> 70713dddf3d2 ("net_sched: introduce tracepoint trace_qdisc_enqueue()")
> >> 851f36e40962 ("net_sched: use %px to print skb address in trace_qdisc_dequeue()")
> >>
> >> However, tracing the packet traversal shows a mix of hashes and real
> >> addresses. Pasting a sample trace for reference-
> >>
> >> ping-14249   [002] .....  3424.046612: netif_rx_entry: dev=lo napi_id=0x3 queue_mapping=0
> >> skbaddr=00000000dcbed83e vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800
> >> ip_summed=0 hash=0x00000000 l4_hash=0 len=84 data_len=0 truesize=768 mac_header_valid=1
> >> mac_header=-14 nr_frags=0 gso_size=0 gso_type=0x0
> >> ping-14249   [002] .....  3424.046615: netif_rx: dev=lo skbaddr=ffffff888e5d1000 len=84
> >>
> >> Switch the trace print formats to %p for all the events to have a
> >> consistent format of printing the hashed addresses in all cases.
> >>
> >
> > This is obscured...
> >
> > What exactly is the inconsistency here? Both are apparently hex, from
> > user's point of view. The only difference is one is an apparently
> > invalid kernel address, the other is not. This difference only matters
> > when you try to dereference it, but I don't think you should do it here,
> > this is not a raw tracepoint at all. You can always use raw tracepoints
> > to dereference it without even bothering whatever we print.
> >
> > Thanks.
>
> Matching skbs addresses (in a particular format) helps to track the
> packet traversal timings / delays in processing.

So... how didn't you notice the duplicated addresses with hashed ones?
It is 100% reproducible to see duplicates with hashed ones.

Thanks.

Re: [PATCH net-next v2] net: Print hashed skb addresses for all net and qdisc events

[Steven Rostedt]

On Sat, 2 Jul 2022 21:36:19 -0700
Cong Wang <xiyou.wangcong@gmail.com> wrote:

> > Matching skbs addresses (in a particular format) helps to track the
> > packet traversal timings / delays in processing.  
> 
> So... how didn't you notice the duplicated addresses with hashed ones?
> It is 100% reproducible to see duplicates with hashed ones.

Yes the hashes are reproducible giving the same address for this exact
purpose (to match like addresses).

I'm not sure if your last sentence was a question or a statement (it did
not end with a question mark).

But I agree with this patch that the trace events that reference the same
address should be consistent in its use of %p and %px, where it uses one or
the other and not mix and match. Because the value itself may not be
important to a trace, but knowing that the value is consistent throughout
the trace with different tracepoints is.

-- Steve