On Wed, 17 Jul 2019, Sudip Mukherjee wrote:
> I am using v4.14.55 on an Intel Atom based board and I am seeing network
> packet drops frequently on wireshark logs. After lots of debugging it
> seems that when this happens softirq is taking huge time to start after
> it has been raised. This is a small snippet from ftrace:
>
> <...>-2110 [001] dNH1 466.634916: irq_handler_entry: irq=126
> name=eth0-TxRx-0
> <...>-2110 [001] dNH1 466.634917: softirq_raise: vec=3
> [action=NET_RX]
> <...>-2110 [001] dNH1 466.634918: irq_handler_exit: irq=126
> ret=handled
> ksoftirqd/1-15 [001] ..s. 466.635826: softirq_entry: vec=3
> [action=NET_RX]
> ksoftirqd/1-15 [001] ..s. 466.635852: softirq_exit: vec=3
> [action=NET_RX]
> ksoftirqd/1-15 [001] d.H. 466.635856: irq_handler_entry: irq=126
> name=eth0-TxRx-0
> ksoftirqd/1-15 [001] d.H. 466.635857: softirq_raise: vec=3
> [action=NET_RX]
> ksoftirqd/1-15 [001] d.H. 466.635858: irq_handler_exit: irq=126
> ret=handled
> ksoftirqd/1-15 [001] ..s. 466.635860: softirq_entry: vec=3
> [action=NET_RX]
> ksoftirqd/1-15 [001] ..s. 466.635863: softirq_exit: vec=3
> [action=NET_RX]
>
> So, softirq was raised at 466.634917 but it started at 466.635826 almost
> 909 usec after it was raised.
This is a situation where the network softirq decided to delegate softirq
processing to ksoftirqd. That happens when too much work is available while
processing softirqs on return from interrupt.
That means that softirq processing happens under scheduler control. So if
there are other runnable tasks on the same CPU ksoftirqd can be delayed
until their time slice expired. As a consequence ksoftirqd might not be
able to catch up with the incoming packet flood and the NIC starts to drop.
You can hack ksoftirq_running() to return always false to avoid this, but
that might cause application starvation and a huge packet buffer backlog
when the amount of incoming packets makes the CPU do nothing else than
softirq processing.
Thanks,
tglx
