RE: [PATCH v1 net] lan743x: fix return value for lan743x_tx_napi_poll

Slightly out of topic I am not sure why NAPI is used on the transmit side.
Originally NAPI was designed to fix the receive interrupt happening on each
receive frame problem, so on transmit side it is to avoid the transmit
done interrupt on each transmit frame?  Typically hardware has a way
to trigger transmit done interrupt or not in each transmit frame.

NAPI may have other uses in newer kernels that I am not aware of.

I notice 2 problems in the driver:

1. netif_napi_add is used instead of netif_tx_napi_add.
2. In all other drivers that use netif_tx_napi_add most do not call napi_complete_done.
They all call napi_complete directly and return 0.

freescale/gianfar.c
rocker/rocker_main.c
ti/cpsw.c

virtio_net.c does use napi_complete_done but it also passes 0 as a parameter.

-----Original Message-----
From: Florian Fainelli <f.fainelli@gmail.com>
Sent: Tuesday, November 20, 2018 2:12 PM
To: Bryan Whitehead - C21958 <Bryan.Whitehead@microchip.com>;
andrew@lunn.ch
Cc: davem@davemloft.net; netdev@vger.kernel.org; UNGLinuxDriver
[off-list ref]
Subject: Re: [PATCH v1 net] lan743x: fix return value for
lan743x_tx_napi_poll

On 11/20/18 1:39 PM, Bryan.Whitehead@microchip.com wrote:

quoted

quoted

-----Original Message-----
From: Andrew Lunn <andrew@lunn.ch>
Sent: Tuesday, November 20, 2018 2:31 PM
To: Bryan Whitehead - C21958 <Bryan.Whitehead@microchip.com>
Cc: davem@davemloft.net; netdev@vger.kernel.org; UNGLinuxDriver
[off-list ref]
Subject: Re: [PATCH v1 net] lan743x: fix return value for
lan743x_tx_napi_poll

On Tue, Nov 20, 2018 at 01:26:43PM -0500, Bryan Whitehead wrote:

quoted

It has been noticed that under stress the lan743x driver will
sometimes hang or cause a kernel panic. It has been noticed that
returning '0' instead of 'weight' fixes this issue.

fixes: rare kernel panic under heavy traffic load.
Signed-off-by: Bryan Whitehead <Bryan.Whitehead@microchip.com>

Hi Bryan

This sounds like a band aid over something which is broken, not a real fix.

Can you show us the stack trace from the panic?

    Andrew

Andrew,

Admittedly, my knowledge of what the kernel is doing behind the scenes is

limited.

quoted

But according to documentation found on
https://wiki.linuxfoundation.org/networking/napi

It states the following
"The poll() function may also process TX completions, in which case if it

processes

quoted

the entire TX ring then it should count that work as the rest of the budget.
Otherwise, TX completions are not counted."

So based on that, the original driver was returning the full budget. But I was

having

quoted

Issues with it. And the above documentation seems to suggest that I could

return 0

quoted

As in "not counted" from above.

I tried it, and my lock up issues disappeared.

Regarding the kernel panic stack trace. So far its very hard to replicate that

on the

quoted

latest kernel. I've seen it more frequently when back porting to older

kernels such

quoted

as 4.14, and 4.9. This same fix caused those kernel panics to disappear.
Are you interested in seeing a stack dump from older kernels?

In the latest kernel the issue manifests as a kernel message which states
"[  945.021101] enp48s0: Budget exhausted after napi rescheduled"

I'm not sure what that means. But it does not lock up immediately after

seeing that

quoted

Message. But it usually locks up with in a minute of seeing that message.

And the sometimes I get the following warning
[ 1240.425020] ------------[ cut here ]------------
[ 1240.426014] NETDEV WATCHDOG: enp0s25 (e1000e): transmit queue 0

timed out

quoted

[ 1240.430027] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:461

dev_watchdog+0x1ef/0x200

quoted

[ 1240.430027] Modules linked in: lan743x
[ 1240.430027] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G          I       4.19.2 #1
[ 1240.430027] Hardware name: Hewlett-Packard HP Compaq dc7900

Convertible Minitower/3032h, BIOS 786G1 v01.16 03/05/2009

quoted

[ 1240.430027] RIP: 0010:dev_watchdog+0x1ef/0x200
[ 1240.430027] Code: 00 48 63 4d e0 eb 93 4c 89 e7 c6 05 68 30 b3 00 01 e8 25

3d fd ff 89 d9 48 89 c2 4c 89 e6 48 c7 c7 98 92 48 ab e8 f1 28 87 ff <0f> 0b eb c0
0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 48 c7 47 08 00

quoted

[ 1240.430027] RSP: 0018:ffff98490be03e90 EFLAGS: 00010282
[ 1240.430027] RAX: 0000000000000000 RBX: 0000000000000000 RCX:

0000000000000000

quoted

[ 1240.497168] RDX: 0000000000040400 RSI: 00000000000000f6 RDI:

0000000000000300

quoted

[ 1240.497168] RBP: ffff984908574440 R08: 0000000000000000 R09:

00000000000003a4

quoted

[ 1240.497168] R10: 0000000000000020 R11: ffffffffabc928ed R12:

ffff984908574000

quoted

[ 1240.497168] R13: 0000000000000000 R14: 0000000000000000 R15:

ffff98490be195b0

quoted

[ 1240.497168] FS:  0000000000000000(0000) GS:ffff98490be00000(0000)

knlGS:0000000000000000

quoted

[ 1240.497168] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1240.497168] CR2: 00007f31cd4c0000 CR3: 0000000109bca000 CR4:

00000000000406f0

quoted

[ 1240.497168] Call Trace:
[ 1240.497168]  <IRQ>
[ 1240.497168]  ? qdisc_reset+0xe0/0xe0
[ 1240.497168]  call_timer_fn+0x26/0x130
[ 1240.497168]  run_timer_softirq+0x1cd/0x400
[ 1240.497168]  ? hpet_interrupt_handler+0x10/0x30
[ 1240.497168]  __do_softirq+0xed/0x2aa
[ 1240.497168]  irq_exit+0xb7/0xc0
[ 1240.497168]  do_IRQ+0x45/0xd0
[ 1240.497168]  common_interrupt+0xf/0xf
[ 1240.497168]  </IRQ>
[ 1240.497168] RIP: 0010:cpuidle_enter_state+0xa6/0x330
[ 1240.497168] Code: 65 8b 3d 1d b0 4d 55 e8 58 6a 95 ff 48 89 c3 66 66 66 66

90 31 ff e8 59 73 95 ff 80 7c 24 0b 00 0f 85 25 02 00 00 fb 4c 29 eb <48> ba cf f7
53 e3 a5 9b c4 20 48 89 d8 48 c1 fb 3f 48 f7 ea b8 ff

quoted

[ 1240.497168] RSP: 0018:ffffffffab603e60 EFLAGS: 00000216 ORIG_RAX:

ffffffffffffffde

quoted

[ 1240.497168] RAX: ffff98490be20a80 RBX: 000000000081035c RCX:

00000120cf178c49

quoted

[ 1240.497168] RDX: 00000120cf178ca0 RSI: 00000120cf178ca0 RDI:

0000000000000000

quoted

[ 1240.497168] RBP: ffff984908fbd000 R08: fffffffb58ea5f9e R09:

000001208e0b48df

quoted

[ 1240.497168] R10: 00000000000018c4 R11: 0000000000002468 R12:

0000000000000002

quoted

[ 1240.497168] R13: 00000120ce968944 R14: ffffffffab6a68a0 R15:

ffffffffab611740

quoted

[ 1240.497168]  do_idle+0x1da/0x230
[ 1240.497168]  cpu_startup_entry+0x6a/0x70
[ 1240.497168]  start_kernel+0x4a2/0x4c2
[ 1240.497168]  secondary_startup_64+0xa4/0xb0
[ 1240.497168] ---[ end trace c6f3be34c214db4e ]---

Notice the warning is referring to a different adapter. So I suspect that

whatever happened it froze

quoted

All network adapters.

If you have suggestions let me know.

Did you look at the output of "perf top" or something along those lines
to figure out if your lan743x driver is indeed responsible for that by
not being scheduler friendly? What is likely happening is that you do
not reclaim "weight" packets and instead keep looping into NAPI context,
which prevents the system from making further progress.

Calling napi_complete_done() for the TX path is not necessary AFAICT,
what you really want to do is call napi_complete() and make sure you:

- reclaim/free as many TX buffers as possible, without looking at the
NAPI weight which becomes irrelevant
- if you have been able to reclaim enough descriptors, wake-up the
transmit queue

So ignoring the NAPI weight like you do is correct, but calling
napi_complete_done() with a 0 argument does not sound correct to me.
--
Florian