rk3399: NETDEV WATCHDOG: eth0 (rk_gmac-dwmac): transmit queue 0 timed out

[jakob-tsd]

On the RK3399 running the release-4.4 kernel, it is fairly easy to lock up the Ethernet interface by running heavy traffic over it. After a few minutes you'll get a kernel message like this:

[ 3067.819477] NETDEV WATCHDOG: eth0 (rk_gmac-dwmac): transmit queue 0 timed out

This has been reported against the Firefly-RK3399 board here but we are also seeing this on our hardware. Is this a known issue?

Let me know if you need help for reproducing this.

[jakob-tsd]

I now have a reproducer that kills ethernet within a few seconds.

You need a Linux server (x86 or whatever, just needs gigabit ethernet). Run two instances of iperf3 server:

iperf3 -s -p 5202 &
iperf3 -s -p 5203

Then, on the the RK3399, save this script as ethammer.sh:

#!/bin/bash -eux
#
# ethammer.sh
#
SERVER=10.2.0.1
iperf3 -c $SERVER -p 5202 -t 3600 -P 2 -T TX &
iperf3 -c $SERVER -p 5203 -t 3600 -P 2 -R -T RX &
wait

You will get something like this when running it:

# ./ethammer.sh
+ SERVER=10.2.0.17
+ iperf3 -c 10.2.0.17 -p 5202 -t 3600 -P 2 -T TX
+ wait
+ iperf3 -c 10.2.0.17 -p 5203 -t 3600 -P 2 -R -T RX
TX:  Connecting to host 10.2.0.17, port 5202
RX:  Connecting to host 10.2.0.17, port 5203
RX:  Reverse mode, remote host 10.2.0.17 is sending
TX:  [  4] local 10.2.143.234 port 58864 connected to 10.2.0.17 port 5202
RX:  [  4] local 10.2.143.234 port 59206 connected to 10.2.0.17 port 5203
TX:  [  6] local 10.2.143.234 port 58868 connected to 10.2.0.17 port 5202
RX:  [  6] local 10.2.143.234 port 59210 connected to 10.2.0.17 port 5203
TX:  [ ID] Interval           Transfer     Bandwidth       Retr  Cwnd
TX:  [  4]   0.00-1.01   sec  45.8 MBytes   382 Mbits/sec    0    672 KBytes
TX:  [  6]   0.00-1.01   sec  43.6 MBytes   363 Mbits/sec    0    503 KBytes
TX:  [SUM]   0.00-1.01   sec  89.4 MBytes   745 Mbits/sec    0
RX:  [ ID] Interval           Transfer     Bandwidth
RX:  [  4]   0.00-1.04   sec  31.2 MBytes   251 Mbits/sec
RX:  [  6]   0.00-1.04   sec  19.9 MBytes   161 Mbits/sec
RX:  [SUM]   0.00-1.04   sec  51.1 MBytes   412 Mbits/sec
TX:  - - - - - - - - - - - - - - - - - - - - - - - - -
TX:  [  4]   1.01-2.00   sec  14.8 MBytes   125 Mbits/sec    1   1.41 KBytes
TX:  [  6]   1.01-2.00   sec  13.6 MBytes   115 Mbits/sec    0   1.41 KBytes
TX:  [SUM]   1.01-2.00   sec  28.4 MBytes   239 Mbits/sec    1
RX:  - - - - - - - - - - - - - - - - - - - - - - - - -
RX:  [  4]   1.04-2.00   sec  25.5 MBytes   223 Mbits/sec
RX:  [  6]   1.04-2.00   sec  24.7 MBytes   216 Mbits/sec
RX:  [SUM]   1.04-2.00   sec  50.2 MBytes   439 Mbits/sec
TX:  - - - - - - - - - - - - - - - - - - - - - - - - -
TX:  [  4]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec    0   1.41 KBytes
TX:  [  6]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec    0   1.41 KBytes
TX:  [SUM]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec    0
RX:  - - - - - - - - - - - - - - - - - - - - - - - - -
RX:  [  4]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec
RX:  [  6]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec
RX:  [SUM]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec
TX:  - - - - - - - - - - - - - - - - - - - - - - - - -
TX:  [  4]   3.00-4.00   sec  0.00 Bytes  0.00 bits/sec    0   1.41 KBytes
TX:  [  6]   3.00-4.00   sec  0.00 Bytes  0.00 bits/sec    0   1.41 KBytes
TX:  [SUM]   3.00-4.00   sec  0.00 Bytes  0.00 bits/sec    0
RX:  - - - - - - - - - - - - - - - - - - - - - - - - -
RX:  [  4]   3.00-4.00   sec  0.00 Bytes  0.00 bits/sec
RX:  [  6]   3.00-4.00   sec  0.00 Bytes  0.00 bits/sec
RX:  [SUM]   3.00-4.00   sec  0.00 Bytes  0.00 bits/sec
^CRX:  - - - - - - - - - - - - - - - - - - - - - - - - -
RX:  [  4]   4.00-4.59   sec  0.00 Bytes  0.00 bits/sec
RX:  [  6]   4.00-4.59   sec  0.00 Bytes  0.00 bits/sec
RX:  [SUM]   4.00-4.59   sec  0.00 Bytes  0.00 bits/sec
RX:  - - - - - - - - - - - - - - - - - - - - - - - - -
RX:  [ ID] Interval           Transfer     Bandwidth
RX:  [  4]   0.00-4.59   sec  0.00 Bytes  0.00 bits/sec                  sender
RX:  [  4]   0.00-4.59   sec  56.7 MBytes   104 Mbits/sec                  receiver
RX:  [  6]   0.00-4.59   sec  0.00 Bytes  0.00 bits/sec                  sender
RX:  [  6]   0.00-4.59   sec  44.7 MBytes  81.6 Mbits/sec                  receiver
RX:  [SUM]   0.00-4.59   sec  0.00 Bytes  0.00 bits/sec                  sender
RX:  [SUM]   0.00-4.59   sec   101 MBytes   185 Mbits/sec                  receiver
iperf3: interrupt - the client has terminated
TX:  - - - - - - - - - - - - - - - - - - - - - - - - -
TX:  [  4]   4.00-4.61   sec  0.00 Bytes  0.00 bits/sec    0   1.41 KBytes
TX:  [  6]   4.00-4.61   sec  0.00 Bytes  0.00 bits/sec    0   1.41 KBytes
TX:  [SUM]   4.00-4.61   sec  0.00 Bytes  0.00 bits/sec    0
TX:  - - - - - - - - - - - - - - - - - - - - - - - - -
TX:  [ ID] Interval           Transfer     Bandwidth       Retr
TX:  [  4]   0.00-4.61   sec  60.6 MBytes   110 Mbits/sec    1             sender
TX:  [  4]   0.00-4.61   sec  0.00 Bytes  0.00 bits/sec                  receiver
TX:  [  6]   0.00-4.61   sec  57.2 MBytes   104 Mbits/sec    0             sender
TX:  [  6]   0.00-4.61   sec  0.00 Bytes  0.00 bits/sec                  receiver
TX:  [SUM]   0.00-4.61   sec   118 MBytes   214 Mbits/sec    1             sender
TX:  [SUM]   0.00-4.61   sec  0.00 Bytes  0.00 bits/sec                  receiver
iperf3: interrupt - the client has terminated

root@rk3399-q7:~# ^C
root@rk3399-q7:~# [  167.764344] NETDEV WATCHDOG: eth0 (rk_gmac-dwmac): transmit queue 0 timed out
[  167.771799] ------------[ cut here ]------------
[  167.776539] WARNING: at net/sched/sch_generic.c:306
[  167.781538] Modules linked in:
[  167.784698]
[  167.786246] CPU: 5 PID: 0 Comm: swapper/5 Not tainted 4.4.70-35223-g5fa317508aaf-dirty #5
[...]

[wzyy2]

Try IRQ Affinity?

@KevanLan @rk-hgc
Could you guys have a look?

[jakob-tsd]

IRQ affinity: Good idea. It looks like the eth0 irq always arrives at CPU0:

# cat /proc/interrupts | grep -e 'CPU0\|eth0'
           CPU0       CPU1       CPU2       CPU3       CPU4       CPU5
 24:      25589          0          0          0          0          0     GICv3  44 Level     eth0

I moved it to CPU5, using echo 20 > /proc/irq/24/smp_affinity, also seems to take affect:

# cat /proc/interrupts | grep -e 'CPU0\|eth0'
           CPU0       CPU1       CPU2       CPU3       CPU4       CPU5
 24:        144          0          0          0          0      56139     GICv3  44 Level     eth0

But the hang still happens after something like two seconds.

[KevanLan]

@rk-hgc will reproduce it by EXCAVATOR board。

[jakob-tsd]

I managed to get rid of the hang by increasing the voltage on the LOGIC_VDD rail. Looks like a power management issue on our board. Wonder if it's a similar story for the Firefly-RK3399. Anyway, I think I'll close this, thanks!