NETDEV WATCHDOG usb1 (cdc_ether): transmit queue 0 timeout on IMX8DX MEK

[shijie_zheng]

Dear support engineer,

I am currently using the IMX8 chip, and “NETDEV WATCHDOG usb1 (cdc_ether): transmit queue 0 timeout” problem occurred when I was using it. I published the Log when the problem occurred,

How do I use this Log to locate the function that's causing the problem?

could you help me analyze the Log and the solution?

------------------------------Log info--------------------------------------

2020/09/01 09:42:22.046041 kernel: Informational: option 1-1:1.7: GSM modem (1-port) converter detected
2020/09/01 09:42:22.045198 klogd[2588]: Informational: [ 16.933346] cdc_ether 1-1:1.4 usb1: register 'cdc_ether' at usb-xhci-cdns3-1, CDC Ethernet Device, d2:b8:1f:a3:50:15
2020/09/01 09:42:22.059630 kernel: Informational: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
2020/09/01 09:42:22.059586 klogd[2588]: Informational: [ 16.945300] option 1-1:1.7: GSM modem (1-port) converter detected
2020/09/01 09:42:22.059607 klogd[2588]: Informational: [ 16.952009] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
2020/09/01 09:42:22.066834 kernel: Informational: option 1-1:1.8: GSM modem (1-port) converter detected
2020/09/01 09:42:22.067665 kernel: Informational: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
2020/09/01 09:42:22.066812 klogd[2588]: Informational: [ 16.959921] option 1-1:1.8: GSM modem (1-port) converter detected
2020/09/01 09:42:22.074450 klogd[2588]: Informational: [ 16.966875] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
2020/09/01 09:42:22.158509 systemd-network[2577]: Informational: rmnet_usb1: Link is not managed by us
2020/09/01 09:42:22.158546 systemd-network[2577]: Informational: lo: Link is not managed by us
2020/09/01 09:42:22.158563 systemd-network[2577]: Informational: sit0: Link is not managed by us
2020/09/01 09:42:22.158983 systemd-network[2577]: Informational: usb1: IPv6 successfully enabled
2020/09/01 09:42:22.173218 systemd-network[2577]: Informational: usb1: Gained carrier
2020/09/01 09:42:22.176450 systemd-timesyn[2578]: Informational: Network configuration changed, trying to establish connection.
2020/09/01 09:42:23.505261 systemd-network[2577]: Informational: usb1: Gained IPv6LL
2020/09/01 09:42:32.358513 kernel: Informational: NETDEV WATCHDOG: usb1 (cdc_ether): transmit queue 0 timed out 4294897592
2020/09/01 09:42:32.358956 kernel: Warning: ------------[ cut here ]------------
2020/09/01 09:42:32.359111 kernel: Warning: WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:319 dev_watchdog+0x2cc/0x2d8
2020/09/01 09:42:32.359245 kernel: Warning: Modules linked in: cryptodev(O)
2020/09/01 09:42:32.359415 kernel: Warning: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G O 4.14.98 #1
2020/09/01 09:42:32.359548 kernel: Warning: Hardware name: Freescale i.MX8DX MEK - NIO (DT)
2020/09/01 09:42:32.359678 kernel: Warning: task: ffff000009934c00 task.stack: ffff000009920000
2020/09/01 09:42:32.359809 kernel: Warning: PC is at dev_watchdog+0x2cc/0x2d8
2020/09/01 09:42:32.359939 kernel: Warning: LR is at dev_watchdog+0x2cc/0x2d8
2020/09/01 09:42:32.360070 kernel: Warning: pc : [<ffff000008a7003c>] lr : [<ffff000008a7003c>] pstate: 20000145
2020/09/01 09:42:32.360202 kernel: Warning: sp : ffff000008003d90
2020/09/01 09:42:32.360332 kernel: Warning: x29: ffff000008003d90 x28: 0000000000000020
2020/09/01 09:42:32.360466 kernel: Warning: x27: ffff000009925180 x26: ffff000009934c00
2020/09/01 09:42:32.360601 kernel: Warning: x25: 00000000ffffffff x24: ffff000009926000
2020/09/01 09:42:32.360790 kernel: Warning: x23: 00000000fffeefb8 x22: ffff80003611941c
2020/09/01 09:42:32.360928 kernel: Warning: x21: 0000000000000000 x20: ffff800036119000
2020/09/01 09:42:32.361059 kernel: Warning: x19: ffff800036b1e600 x18: 0000000000000010
2020/09/01 09:42:32.361190 kernel: Warning: x17: 0000ffffbc463168 x16: 0000000000000000
2020/09/01 09:42:32.361321 kernel: Warning: x15: ffffffffffffffff x14: 32342074756f2064
2020/09/01 09:42:32.361451 kernel: Warning: x13: 656d697420302065 x12: ffff000009929e78
2020/09/01 09:42:32.361584 kernel: Warning: x11: ffff0000083b3e80 x10: 72656874655f6364
2020/09/01 09:42:32.361717 kernel: Warning: x9 : 0000000000000015 x8 : 3a474f4448435441
2020/09/01 09:42:32.361854 kernel: Warning: x7 : 572056454454454e x6 : 000000000000014c
2020/09/01 09:42:32.362016 kernel: Warning: x5 : 0000000000000001 x4 : 0000000000000002
2020/09/01 09:42:32.362163 kernel: Warning: x3 : 0000000000000000 x2 : 0000000000000040
2020/09/01 09:42:32.362301 kernel: Warning: x1 : ffff000009934c00 x0 : 0000000000000049
2020/09/01 09:42:32.362443 kernel: Warning: Call trace:
2020/09/01 09:42:32.362585 kernel: Warning: Exception stack(0xffff000008003c50 to 0xffff000008003d90)
2020/09/01 09:42:32.362727 kernel: Warning: 3c40: 0000000000000049 ffff000009934c00
2020/09/01 09:42:32.362877 kernel: Warning: 3c60: 0000000000000040 0000000000000000 0000000000000002 0000000000000001
2020/09/01 09:42:32.363022 kernel: Warning: 3c80: 000000000000014c 572056454454454e 3a474f4448435441 0000000000000015
2020/09/01 09:42:32.363161 kernel: Warning: 3ca0: 72656874655f6364 ffff0000083b3e80 ffff000009929e78 656d697420302065
2020/09/01 09:42:32.363301 kernel: Warning: 3cc0: 32342074756f2064 ffffffffffffffff 0000000000000000 0000ffffbc463168
2020/09/01 09:42:32.363439 kernel: Warning: 3ce0: 0000000000000010 ffff800036b1e600 ffff800036119000 0000000000000000
2020/09/01 09:42:32.363591 kernel: Warning: 3d00: ffff80003611941c 00000000fffeefb8 ffff000009926000 00000000ffffffff
2020/09/01 09:42:32.363744 kernel: Warning: 3d20: ffff000009934c00 ffff000009925180 0000000000000020 ffff000008003d90
2020/09/01 09:42:32.363887 kernel: Warning: 3d40: ffff000008a7003c ffff000008003d90 ffff000008a7003c 0000000020000145
2020/09/01 09:42:32.364035 kernel: Warning: 3d60: ffff000008f9ed58 0000000000000000 0000ffffffffffff 00000000000000c0
2020/09/01 09:42:32.364177 kernel: Warning: 3d80: ffff000008003d90 ffff000008a7003c
2020/09/01 09:42:32.364318 kernel: Warning: [<ffff000008a7003c>] dev_watchdog+0x2cc/0x2d8
2020/09/01 09:42:32.364464 kernel: Warning: [<ffff000008125ba4>] call_timer_fn.isra.5+0x24/0x80
2020/09/01 09:42:32.364602 kernel: Warning: [<ffff000008125ca4>] expire_timers+0xa4/0xb0
2020/09/01 09:42:32.365166 kernel: Warning: [<ffff000008125d64>] run_timer_softirq+0xb4/0x170
2020/09/01 09:42:32.365274 kernel: Warning: [<ffff000008081204>] __do_softirq+0x124/0x218
2020/09/01 09:42:32.365392 kernel: Warning: [<ffff0000080cb648>] irq_exit+0xd0/0xf0
2020/09/01 09:42:32.365498 kernel: Warning: [<ffff00000810f278>] __handle_domain_irq+0x60/0xb8
2020/09/01 09:42:32.365607 kernel: Warning: [<ffff000008080fe0>] gic_handle_irq+0x78/0x174
2020/09/01 09:42:32.365719 kernel: Warning: Exception stack(0xffff000009923dd0 to 0xffff000009923f10)
2020/09/01 09:42:32.365830 kernel: Warning: 3dc0: 0000000000000000 0000000000000000
2020/09/01 09:42:32.365938 kernel: Warning: 3de0: 0000000000000001 0000000000000000 ffff000009916108 ffff000009923f00
2020/09/01 09:42:32.366045 kernel: Warning: 3e00: 0000800034649000 0000000000000000 0000000000000002 ffff000009923e90
2020/09/01 09:42:32.366153 kernel: Warning: 3e20: 0000000000000870 0000000000000000 0000000000000000 0000000000000000
2020/09/01 09:42:32.366263 kernel: Warning: 3e40: 0000ffffbc454c38 0000ffffbc452dd8 ffff000008128820 0000ffffbc463168
2020/09/01 09:42:32.366380 kernel: Warning: 3e60: 00000000000000b6 ffff000009912018 ffff000009929000 ffff000009929000
2020/09/01 09:42:32.366499 kernel: Warning: 3e80: ffff00000991bc38 ffff000009929f18 0000000000000000 0000000000000000
2020/09/01 09:42:32.366613 kernel: Warning: 3ea0: ffff000009934c00 0000000000000400 0000000081290018 ffff000009923f10
2020/09/01 09:42:32.366722 kernel: Warning: 3ec0: ffff000008084e94 ffff000009923f10 ffff000008084e98 0000000000000145
2020/09/01 09:42:32.366831 kernel: Warning: 3ee0: 0000000000000000 00000000bde74b80 ffffffffffffffff ffff000008135f74
2020/09/01 09:42:32.366940 kernel: Warning: 3f00: ffff000009923f10 ffff000008084e98
2020/09/01 09:42:32.367048 kernel: Warning: [<ffff000008082a30>] el1_irq+0xb0/0x124
2020/09/01 09:42:32.367156 kernel: Warning: [<ffff000008084e98>] arch_cpu_idle+0x10/0x18
2020/09/01 09:42:32.367266 kernel: Warning: [<ffff0000081012a0>] do_idle+0x120/0x1e0
2020/09/01 09:42:32.367383 kernel: Warning: [<ffff0000081014f8>] cpu_startup_entry+0x20/0x28
2020/09/01 09:42:32.367489 kernel: Warning: [<ffff000008c32118>] rest_init+0xd0/0xe0
2020/09/01 09:42:32.367598 kernel: Warning: [<ffff000009090b58>] start_kernel+0x380/0x394
2020/09/01 09:42:32.367704 kernel: Warning: ---[ end trace 4b0fb03653a0ff81 ]---

[Rach]

We get the same on our iMX8 running Linux version 5.4.70. This usually occurs at startup time:

[ 31.968924] ------------[ cut here ]------------
[ 31.968941] NETDEV WATCHDOG: usb0 (cdc_ether): transmit queue 0 timed out
[ 31.969013] WARNING: CPU: 0 PID: 919 at ../../../../../work-shared/imx8-xl-bsrf/kernel-source/net/sched/sch_generic.c:454 dev_watchdog+0x3c4/0x3d0
[ 31.969017] Modules linked in: ip6table_filter(E) ip6table_mangle(E) ip6_tables(E) iptable_mangle(E) rmnet_ctl(E) rmnet_core(E) iptable_filter(E) ip_tables(E) hwinfo(OE) cryptodev(OE) ase(POE)
[ 31.969052] CPU: 0 PID: 919 Comm: DR-GEN Tainted: P OE 5.4.70-conti-5.4.x+ #1
[ 31.969056] Hardware name: i.MX8SXL GM GEN12 (DT)
[ 31.969062] pstate: 40000005 (nZcv daif -PAN -UAO)
[ 31.969069] pc : dev_watchdog+0x3c4/0x3d0
[ 31.969075] lr : dev_watchdog+0x3c4/0x3d0
[ 31.969078] sp : ffff800010003d50
[ 31.969081] x29: ffff800010003d50 x28: 0000000000000001
[ 31.969087] x27: 0000000000000004 x26: 0000000000000140
[ 31.969093] x25: ffff000015282480 x24: 00000000ffffffff
[ 31.969099] x23: ffff00001948f41c x22: ffff800011056000
[ 31.969105] x21: ffff00001948f000 x20: ffff00001948f438
[ 31.969111] x19: 0000000000000000 x18: 0000000000000000
[ 31.969117] x17: 0000000000000000 x16: 0000000000000000
[ 31.969123] x15: ffff00001935c010 x14: ffffffffffffffff
[ 31.969129] x13: 0000000000000000 x12: ffff8000111b0000
[ 31.969135] x11: ffff80001107d000 x10: ffff8000111b06c8
[ 31.969141] x9 : 0000000000000000 x8 : 0000000000000004
[ 31.969147] x7 : 0000000000000146 x6 : ffff8000111b0000
[ 31.969153] x5 : ffff00001feaf818 x4 : 0000000000000001
[ 31.969159] x3 : ffff00001feaf818 x2 : 0000000000000007
[ 31.969165] x1 : d40fa13fe174e600 x0 : 0000000000000000
[ 31.969171] Call trace:
[ 31.969179] dev_watchdog+0x3c4/0x3d0
[ 31.969188] call_timer_fn+0x3c/0x1e8
[ 31.969194] run_timer_softirq+0x1b4/0x2c8
[ 31.969201] __do_softirq+0x138/0x3cc
[ 31.969207] irq_exit+0x7c/0x88
[ 31.969215] __handle_domain_irq+0x70/0xc0
[ 31.969220] gic_handle_irq+0x6c/0x160
[ 31.969226] el0_irq_naked+0x4c/0x54
[ 31.969230] ---[ end trace af365b315c49a6ad ]---

[Dhruvit]

Hi @shijie_zheng,

I hope you are doing well.

->To locate the function one can use the below command
grep -rin "NETDEV WATCHDOG"

->the function one will come to know that causing the issue is given below
static void dev_watchdog(struct timer_list *t)

the location of this function is given below
<source_code_bsp>/net/sched/sch_generic.c

Thanks & Regards,
Dhruvit Vasavada

[shijie_zheng]

Dear Dhruvit,

From the Log I see that the problem is in sch_generic.c,
I searched on the Internet and found that there are some people  also encountered similar problems.

Do you have any idea about the cause of this problem? Does this look like a kernel BUG?

In fact, I want to know how to solve this problem.

[Dhruvit]

Hi @shijie_zheng,

->Reason for getting this message is mentioned below.

some_queue_timedout becomes 1

further, it's seen that dev->name usb1 and its driver cdc-ether are not able to send the data because
netif_xmit_stopped & time_after these two returns 1 and eventually error occurred.

time_after(a,b) returns true if the time a is after time b.
netif_queue_stopped -> test if transmit queue is flow blocked
-it tests if transmit queue on the device is currently unable to send.

please look into these functions, why they are unable to send, is there any transmission already happening on the same.
Kindly share the setup details to debug it further

Thanks & Regards,
Dhruvit Vasavada