Linux FTRACE function_graph process context

Question

I've a question related to the use of ftrace on Linux kernel 4.15. ftrace is configured as follows:

mount -t debugfs nodev /sys/kernel/debug
echo funcgraph-proc > /sys/kernel/debug/tracing/trace_options
echo function_graph >/sys/kernel/debug/tracing/current_tracer
echo *gro_receive > /sys/kernel/debug/tracing/set_graph_function
echo > /sys/kernel/debug/tracing/trace
echo 1 >/sys/kernel/debug/tracing/tracing_on
sleep 2
echo 0 >/sys/kernel/debug/tracing/tracing_on
cat /sys/kernel/debug/tracing/trace > ./result.out

The following are two excerpts of the trace output (result.out).

0)  sleep-13890   =>    <idle>-0   
 ------------------------------------------

 0)    <idle>-0    |               |  napi_gro_receive() {
 0)    <idle>-0    |   0.255 us    |    skb_gro_reset_offset();
 0)    <idle>-0    |               |    dev_gro_receive() {
 0)    <idle>-0    |               |      inet_gro_receive() {
 0)    <idle>-0    |               |        tcp4_gro_receive() {
 0)    <idle>-0    |   0.307 us    |          tcp_gro_receive();
 0)    <idle>-0    |   1.007 us    |        }
 0)    <idle>-0    |   1.725 us    |      }
 0)    <idle>-0    |   2.396 us    |    }
 0)    <idle>-0    |               |    netif_receive_skb_internal() {
 0)    <idle>-0    |   0.171 us    |      ktime_get_with_offset();
 0)    <idle>-0    |   0.174 us    |      skb_defer_rx_timestamp();
 0)    <idle>-0    |               |      __netif_receive_skb() {
 0)    <idle>-0    |               |        __netif_receive_skb_core() {
 0)    <idle>-0    |               |          tpacket_rcv() {


 1)    <idle>-0    =>   ksoftir-17  
 ------------------------------------------

 1)   ksoftir-17   |   0.327 us    |  finish_task_switch();
 1)   ksoftir-17   |               |  napi_gro_receive() {
 1)   ksoftir-17   |   0.238 us    |    skb_gro_reset_offset();
 1)   ksoftir-17   |               |    dev_gro_receive() {
 1)   ksoftir-17   |   0.166 us    |      inet_gro_receive();
 1)   ksoftir-17   |   0.472 us    |    }
 1)   ksoftir-17   |               |    netif_receive_skb_internal() {
 1)   ksoftir-17   |   0.178 us    |      ktime_get_with_offset();
 1)   ksoftir-17   |   0.143 us    |      skb_defer_rx_timestamp();
 1)   ksoftir-17   |               |      __netif_receive_skb() {
 1)   ksoftir-17   |               |        __netif_receive_skb_core() {
 1)   ksoftir-17   |               |          tpacket_rcv() {

As you can see the calls to napi_gro_receive() are shown as in the context of different processes. From my understanding it should be always called in the context of a ksoftirq, but I can see it just in the 2nd occurrence in the trace.

Is the above the expected behavior ? Thanks.

Answer 1

napi_gro_receive is part of under BH context The portion of interrupt processing that is performed on the high priority work queue with interrupts enabled is referred to as Bottom Half Interrupt processing.