| Message ID | 1656106465-26544-1-git-send-email-quic_subashab@quicinc.com (mailing list archive) |
|---|---|
| State | Accepted |
| Commit | 6deb209dc6b0952a460da17ee61223ee3b3429d5 |
| Delegated to: | Netdev Maintainers |
| Headers | show |
| Series | [net-next,v2] net: Print hashed skb addresses for all net and qdisc events | expand |
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!
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.
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.
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.
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
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) );
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(-)