[v3] net: Add trace events for all receive exit points

Trace events are already present for the receive entry points, to indicate
how the reception entered the stack.

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.

Without this, it is not possible with tracepoint instrumentation 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. It is possible using other mechanisms
like kretprobes, but considering the "entry" points are already present,
it would be good to add the matching exit events.

In addition to linking packets with wakeups, the entry/exit event pair
can also be used to perform network stack latency analyses.

Signed-off-by: Geneviève Bastien <gbastien@versatic.net>
CC: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
CC: Steven Rostedt <rostedt@goodmis.org>
CC: Ingo Molnar <mingo@redhat.com>
CC: David S. Miller <davem@davemloft.net>
Reviewed-by: Steven Rostedt (VMware) <rostedt@goodmis.org> (tracing
side)
---
Changes in v3:
  - Update commit message
  - Rename exit template to match the entry one
  - Move the similar tracepoints together in the code
---
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 | 71 ++++++++++++++++++++++++++++++++++++++
 net/core/dev.c             | 38 ++++++++++++++++----
 2 files changed, 103 insertions(+), 6 deletions(-)

From: Geneviève Bastien <gbastien@versatic.net>
Date: Tue, 13 Nov 2018 15:13:26 -0500

> @@ -5222,9 +5228,14 @@ static void netif_receive_skb_list_internal(struct list_head *head)
>   */
>  int netif_receive_skb(struct sk_buff *skb)
>  {
> +	int ret;
> +
>  	trace_netif_receive_skb_entry(skb);
>  
> -	return netif_receive_skb_internal(skb);
> +	ret = netif_receive_skb_internal(skb);
> +	trace_netif_receive_skb_exit(skb, ret);

Every time I read this code from now on I'm going to say to myself
"oh crap, we reference 'skb' after it's potentially freed up"

I really don't like this.

I know only the pointer is used, but that pointer can be reallocated
to another SLAB object, even another SKB, by the time these exit
tracepoints execute.

Sorry, I can't really convince myself to apply this now.

----- On Nov 16, 2018, at 10:50 PM, David S. Miller davem@davemloft.net wrote:

> From: Geneviève Bastien <gbastien@versatic.net>
> Date: Tue, 13 Nov 2018 15:13:26 -0500
> 
>> @@ -5222,9 +5228,14 @@ static void netif_receive_skb_list_internal(struct
>> list_head *head)
>>   */
>>  int netif_receive_skb(struct sk_buff *skb)
>>  {
>> +	int ret;
>> +
>>  	trace_netif_receive_skb_entry(skb);
>>  
>> -	return netif_receive_skb_internal(skb);
>> +	ret = netif_receive_skb_internal(skb);
>> +	trace_netif_receive_skb_exit(skb, ret);
> 
> Every time I read this code from now on I'm going to say to myself
> "oh crap, we reference 'skb' after it's potentially freed up"
> 
> I really don't like this.
> 
> I know only the pointer is used, but that pointer can be reallocated
> to another SLAB object, even another SKB, by the time these exit
> tracepoints execute.
> 
> Sorry, I can't really convince myself to apply this now.

Hi David,

Thanks for looking into this patch. You bring a very good point indeed!
Passing a skb pointer that may have been already reallocated to skb_exit
tracepoints is pretty much useless for analysis purposes.

I see two possible solutions:

1) Remove the "skb" argument from the sbk_exit tracepoints completely.
Anyway, I think it's not really needed for analysis purposes because
we can link the "entry" with the associated "exit" using the thread ID
executing those tracepoints.  (Geneviève, would that work for your
analyses ?)

2) Move the skb_exit tracepoints before freeing the skb pointer. My
concern here is that the instrumentation may become much uglier than
the currently proposed patch. (I have not looked at the specifics
though, so I may be wrong.)

Do you have a preference between those two approaches, or perhaps you
have an alternative solution in mind ?

Thanks!

Mathieu

From: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Date: Sat, 17 Nov 2018 13:27:29 -0500 (EST)

> I see two possible solutions:
> 
> 1) Remove the "skb" argument from the sbk_exit tracepoints completely.
> Anyway, I think it's not really needed for analysis purposes because
> we can link the "entry" with the associated "exit" using the thread ID
> executing those tracepoints.  (Geneviève, would that work for your
> analyses ?)
> 
> 2) Move the skb_exit tracepoints before freeing the skb pointer. My
> concern here is that the instrumentation may become much uglier than
> the currently proposed patch. (I have not looked at the specifics
> though, so I may be wrong.)
> 
> Do you have a preference between those two approaches, or perhaps you
> have an alternative solution in mind ?

I wonder how other situations handle this.

About #2, if you put the tracepoint beforehand you can't log the
'ret' value.  So at least in that regard I prefer #1.

If tracepoints generally handle this by matching up the thread
ID, then definitely that's how we should do it here too instead
of trying to use the SKB pointer for this purpose.

On 2018-11-18 1:19 a.m., David Miller wrote:
> From: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
> Date: Sat, 17 Nov 2018 13:27:29 -0500 (EST)
>
>> I see two possible solutions:
>>
>> 1) Remove the "skb" argument from the sbk_exit tracepoints completely.
>> Anyway, I think it's not really needed for analysis purposes because
>> we can link the "entry" with the associated "exit" using the thread ID
>> executing those tracepoints.  (Genevi�ve, would that work for your
>> analyses ?)
>>
>> 2) Move the skb_exit tracepoints before freeing the skb pointer. My
>> concern here is that the instrumentation may become much uglier than
>> the currently proposed patch. (I have not looked at the specifics
>> though, so I may be wrong.)
>>
>> Do you have a preference between those two approaches, or perhaps you
>> have an alternative solution in mind ?
> I wonder how other situations handle this.
>
> About #2, if you put the tracepoint beforehand you can't log the
> 'ret' value.  So at least in that regard I prefer #1.
>
> If tracepoints generally handle this by matching up the thread
> ID, then definitely that's how we should do it here too instead
> of trying to use the SKB pointer for this purpose.

I would go for #1 too, the "skb" is not used to match entry/exit, it is more the context in which they appear (thread, softirq, etc). And I did indeed get seg faults on my first attempt when I tried to use the existing templates.

There's just the list tracepoint that would now log nothing, so there's no point looping through the list.

On 2018-11-19 10:27 a.m., Geneviève Bastien wrote:
> On 2018-11-18 1:19 a.m., David Miller wrote:
>> From: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
>> Date: Sat, 17 Nov 2018 13:27:29 -0500 (EST)
>>
>>> I see two possible solutions:
>>>
>>> 1) Remove the "skb" argument from the sbk_exit tracepoints completely.
>>> Anyway, I think it's not really needed for analysis purposes because
>>> we can link the "entry" with the associated "exit" using the thread ID
>>> executing those tracepoints.  (Genevi�ve, would that work for your
>>> analyses ?)
>>>
>>> 2) Move the skb_exit tracepoints before freeing the skb pointer. My
>>> concern here is that the instrumentation may become much uglier than
>>> the currently proposed patch. (I have not looked at the specifics
>>> though, so I may be wrong.)
>>>
>>> Do you have a preference between those two approaches, or perhaps you
>>> have an alternative solution in mind ?
>> I wonder how other situations handle this.
>>
>> About #2, if you put the tracepoint beforehand you can't log the
>> 'ret' value.  So at least in that regard I prefer #1.
>>
>> If tracepoints generally handle this by matching up the thread
>> ID, then definitely that's how we should do it here too instead
>> of trying to use the SKB pointer for this purpose.
> I would go for #1 too, the "skb" is not used to match entry/exit, it is more the context in which they appear (thread, softirq, etc). And I did indeed get seg faults on my first attempt when I tried to use the existing templates.
>
> There's just the list tracepoint that would now log nothing, so there's no point looping through the list.
>
After further investigation, the 'netif_receive_skb_list_exit' tracepoint poses a problem: There is no return value in that function and the TRACE_EVENT infrastructure does not support tracepoints without payload, afaik.

Here's a few possible solutions:

1) Add a unique trace_netif_receive_skb_list_exit tracepoint with a 'fake' return value of 0, so it can use the same template as the others. Easiest, but looks hackish.

2) Add tracepoints in the callees in the various locations where individual skbs get removed from the list. But that's quite a few code paths to cover, and we may miss a few.

3) Simply ignore the exit of the list code path. Dependency analyses will miss this case though.

4) Replace the proposed exit tracepoints by others after the delivery of packets, ie in the 'netif_receive_skb_internal' and 'netif_receive_skb_list_internal' functions, again at the risk of missing code paths.

5) None of the above (and fallback to using kretprobes with the tracers)


Any one of these approaches sound more appealing?

Thanks,

Geneviève