From mboxrd@z Thu Jan 1 00:00:00 1970 From: Mathieu Desnoyers Subject: Re: [PATCH v2] net: Add trace events for all receive exit points Date: Mon, 12 Nov 2018 15:37:16 -0500 (EST) Message-ID: <1185714131.4030.1542055036467.JavaMail.zimbra@efficios.com> References: <20181112194405.4133-1-gbastien@versatic.net> <879033794.3997.1542053367213.JavaMail.zimbra@efficios.com> <2134979231.4006.1542054055701.JavaMail.zimbra@efficios.com> Mime-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Cc: "David S. Miller" , netdev , rostedt , Ingo Molnar To: =?utf-8?Q?Genevi=C3=A8ve?= Bastien Return-path: Received: from mail.efficios.com ([167.114.142.138]:58632 "EHLO mail.efficios.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1725861AbeKMGcK (ORCPT ); Tue, 13 Nov 2018 01:32:10 -0500 In-Reply-To: <2134979231.4006.1542054055701.JavaMail.zimbra@efficios.com> Sender: netdev-owner@vger.kernel.org List-ID: ----- On Nov 12, 2018, at 3:20 PM, Mathieu Desnoyers mathieu.desnoyers@effi= cios.com wrote: > ----- On Nov 12, 2018, at 3:09 PM, Mathieu Desnoyers > mathieu.desnoyers@efficios.com wrote: >=20 >> ----- On Nov 12, 2018, at 2:44 PM, Genevi=C3=A8ve Bastien gbastien@versa= tic.net >> wrote: >>=20 >>> Trace events are already present for the receive entry points, to indic= ate >>> how the reception entered the stack. >>>=20 >>> This patch adds the corresponding exit trace events that will bound the >>> reception such that all events occurring between the entry and the exit >>> can be considered as part of the reception context. This greatly helps >>> for dependency and root cause analyses. >>>=20 >>> Without this, it is impossible to determine whether a sched_wakeup >>> event following a netif_receive_skb event is the result of the packet >>> reception or a simple coincidence after further processing by the >>> thread. >>=20 >> As discussed over IRC, it is _possible_ to use kretprobes to instrument >> the exit, but it is not practical. A v3 will be sent soon to clarify >> this part of the commit message. >>=20 >> Also, I wonder if we should use "net_dev_template_exit" for the event >> class rather than "net_dev_template_return" ? >=20 > Hrm, looking at this again, I notice that there is a single DEFINE_EVENT > using net_dev_template_simple. >=20 > We could simply turn netif_receive_skb_list_exit into a TRACE_EVENT(), > remove the net_dev_template_simple, and rename the net_dev_template_retur= n > to net_dev_template ? >=20 > It's pretty clear from the prototype that it expects a "ret" argument, > so I don't see the need to also state it in the template name. As you pointed out on IRC, net_dev_template already exists. So we can use "net_dev_rx_exit_template" which is along the same lines as its entry counterpart "net_dev_rx_verbose_template". Thanks, Mathieu >=20 > Thanks, >=20 > Mathieu >=20 >>=20 >> Thanks, >>=20 >> Mathieu >>=20 >>>=20 >>> Signed-off-by: Genevi=C3=A8ve Bastien >>> CC: Mathieu Desnoyers >>> CC: Steven Rostedt >>> CC: Ingo Molnar >>> CC: David S. Miller >>> --- >>> Changes in v2: >>> - Add the return value to tracepoints where applicable >>> - Verify if tracepoint is enabled before walking list in >>> netif_receive_skb_list >>> --- >>> include/trace/events/net.h | 78 ++++++++++++++++++++++++++++++++++++++ >>> net/core/dev.c | 38 ++++++++++++++++--- >>> 2 files changed, 110 insertions(+), 6 deletions(-) >>>=20 >>> diff --git a/include/trace/events/net.h b/include/trace/events/net.h >>> index 00aa72ce0e7c..cff1a7b9d0bb 100644 >>> --- a/include/trace/events/net.h >>> +++ b/include/trace/events/net.h >>> @@ -117,6 +117,42 @@ DECLARE_EVENT_CLASS(net_dev_template, >>> =09=09__get_str(name), __entry->skbaddr, __entry->len) >>> ) >>>=20 >>> +DECLARE_EVENT_CLASS(net_dev_template_return, >>> + >>> +=09TP_PROTO(struct sk_buff *skb, int ret), >>> + >>> +=09TP_ARGS(skb, ret), >>> + >>> +=09TP_STRUCT__entry( >>> +=09=09__field(void *,=09skbaddr) >>> +=09=09__field(int,=09ret) >>> +=09), >>> + >>> +=09TP_fast_assign( >>> +=09=09__entry->skbaddr =3D skb; >>> +=09=09__entry->ret =3D ret; >>> +=09), >>> + >>> +=09TP_printk("skbaddr=3D%p ret=3D%d", __entry->skbaddr, __entry->ret) >>> +) >>> + >>> +DECLARE_EVENT_CLASS(net_dev_template_simple, >>> + >>> +=09TP_PROTO(struct sk_buff *skb), >>> + >>> +=09TP_ARGS(skb), >>> + >>> +=09TP_STRUCT__entry( >>> +=09=09__field(void *,=09skbaddr) >>> +=09), >>> + >>> +=09TP_fast_assign( >>> +=09=09__entry->skbaddr =3D skb; >>> +=09), >>> + >>> +=09TP_printk("skbaddr=3D%p", __entry->skbaddr) >>> +) >>> + >>> DEFINE_EVENT(net_dev_template, net_dev_queue, >>>=20 >>> =09TP_PROTO(struct sk_buff *skb), >>> @@ -244,6 +280,48 @@ DEFINE_EVENT(net_dev_rx_verbose_template, >>> netif_rx_ni_entry, >>> =09TP_ARGS(skb) >>> ); >>>=20 >>> +DEFINE_EVENT(net_dev_template_return, napi_gro_frags_exit, >>> + >>> +=09TP_PROTO(struct sk_buff *skb, int ret), >>> + >>> +=09TP_ARGS(skb, ret) >>> +); >>> + >>> +DEFINE_EVENT(net_dev_template_return, napi_gro_receive_exit, >>> + >>> +=09TP_PROTO(struct sk_buff *skb, int ret), >>> + >>> +=09TP_ARGS(skb, ret) >>> +); >>> + >>> +DEFINE_EVENT(net_dev_template_return, netif_receive_skb_exit, >>> + >>> +=09TP_PROTO(struct sk_buff *skb, int ret), >>> + >>> +=09TP_ARGS(skb, ret) >>> +); >>> + >>> +DEFINE_EVENT(net_dev_template_simple, netif_receive_skb_list_exit, >>> + >>> +=09TP_PROTO(struct sk_buff *skb), >>> + >>> +=09TP_ARGS(skb) >>> +); >>> + >>> +DEFINE_EVENT(net_dev_template_return, netif_rx_exit, >>> + >>> +=09TP_PROTO(struct sk_buff *skb, int ret), >>> + >>> +=09TP_ARGS(skb, ret) >>> +); >>> + >>> +DEFINE_EVENT(net_dev_template_return, netif_rx_ni_exit, >>> + >>> +=09TP_PROTO(struct sk_buff *skb, int ret), >>> + >>> +=09TP_ARGS(skb, ret) >>> +); >>> + >>> #endif /* _TRACE_NET_H */ >>>=20 >>> /* This part must be outside protection */ >>> diff --git a/net/core/dev.c b/net/core/dev.c >>> index 0ffcbdd55fa9..c4dc5df34abe 100644 >>> --- a/net/core/dev.c >>> +++ b/net/core/dev.c >>> @@ -4520,9 +4520,14 @@ static int netif_rx_internal(struct sk_buff *skb= ) >>>=20 >>> int netif_rx(struct sk_buff *skb) >>> { >>> +=09int ret; >>> + >>> =09trace_netif_rx_entry(skb); >>>=20 >>> -=09return netif_rx_internal(skb); >>> +=09ret =3D netif_rx_internal(skb); >>> +=09trace_netif_rx_exit(skb, ret); >>> + >>> +=09return ret; >>> } >>> EXPORT_SYMBOL(netif_rx); >>>=20 >>> @@ -4537,6 +4542,7 @@ int netif_rx_ni(struct sk_buff *skb) >>> =09if (local_softirq_pending()) >>> =09=09do_softirq(); >>> =09preempt_enable(); >>> +=09trace_netif_rx_ni_exit(skb, err); >>>=20 >>> =09return err; >>> } >>> @@ -5222,9 +5228,14 @@ static void netif_receive_skb_list_internal(stru= ct >>> list_head *head) >>> */ >>> int netif_receive_skb(struct sk_buff *skb) >>> { >>> +=09int ret; >>> + >>> =09trace_netif_receive_skb_entry(skb); >>>=20 >>> -=09return netif_receive_skb_internal(skb); >>> +=09ret =3D netif_receive_skb_internal(skb); >>> +=09trace_netif_receive_skb_exit(skb, ret); >>> + >>> +=09return ret; >>> } >>> EXPORT_SYMBOL(netif_receive_skb); >>>=20 >>> @@ -5244,9 +5255,15 @@ void netif_receive_skb_list(struct list_head *he= ad) >>>=20 >>> =09if (list_empty(head)) >>> =09=09return; >>> -=09list_for_each_entry(skb, head, list) >>> -=09=09trace_netif_receive_skb_list_entry(skb); >>> +=09if (trace_netif_receive_skb_list_entry_enabled()) { >>> +=09=09list_for_each_entry(skb, head, list) >>> +=09=09=09trace_netif_receive_skb_list_entry(skb); >>> +=09} >>> =09netif_receive_skb_list_internal(head); >>> +=09if (trace_netif_receive_skb_list_exit_enabled()) { >>> +=09=09list_for_each_entry(skb, head, list) >>> +=09=09=09trace_netif_receive_skb_list_exit(skb); >>> +=09} >>> } >>> EXPORT_SYMBOL(netif_receive_skb_list); >>>=20 >>> @@ -5634,12 +5651,17 @@ static gro_result_t napi_skb_finish(gro_result_= t ret, >>> struct sk_buff *skb) >>>=20 >>> gro_result_t napi_gro_receive(struct napi_struct *napi, struct sk_buff = *skb) >>> { >>> +=09gro_result_t ret; >>> + >>> =09skb_mark_napi_id(skb, napi); >>> =09trace_napi_gro_receive_entry(skb); >>>=20 >>> =09skb_gro_reset_offset(skb); >>>=20 >>> -=09return napi_skb_finish(dev_gro_receive(napi, skb), skb); >>> +=09ret =3D napi_skb_finish(dev_gro_receive(napi, skb), skb); >>> +=09trace_napi_gro_receive_exit(skb, ret); >>> + >>> +=09return ret; >>> } >>> EXPORT_SYMBOL(napi_gro_receive); >>>=20 >>> @@ -5753,6 +5775,7 @@ static struct sk_buff *napi_frags_skb(struct napi= _struct >>> *napi) >>>=20 >>> gro_result_t napi_gro_frags(struct napi_struct *napi) >>> { >>> +=09gro_result_t ret; >>> =09struct sk_buff *skb =3D napi_frags_skb(napi); >>>=20 >>> =09if (!skb) >>> @@ -5760,7 +5783,10 @@ gro_result_t napi_gro_frags(struct napi_struct *= napi) >>>=20 >>> =09trace_napi_gro_frags_entry(skb); >>>=20 >>> -=09return napi_frags_finish(napi, skb, dev_gro_receive(napi, skb)); >>> +=09ret =3D napi_frags_finish(napi, skb, dev_gro_receive(napi, skb)); >>> +=09trace_napi_gro_frags_exit(skb, ret); >>> + >>> +=09return ret; >>> } >>> EXPORT_SYMBOL(napi_gro_frags); >>>=20 >>> -- >>> 2.19.1 >>=20 >> -- >> Mathieu Desnoyers >> EfficiOS Inc. >> http://www.efficios.com >=20 > -- > Mathieu Desnoyers > EfficiOS Inc. > http://www.efficios.com --=20 Mathieu Desnoyers EfficiOS Inc. http://www.efficios.com