Problem with TP-Link TL-WN722N

[sodar]

I've got strange problem with this wifi dongle. It is detected on plug and works flawlessly, but after few minutes to few hours time, it freezes, with led on. At that time any sudo command freezes until i unplug the device (so ifup/ifdown freezes too). It uses 'ath9k_htc' driver.
Relevant dmesg:

Code: Select all

Nov 20 09:04:11 raspberrypi kernel: [44753.644931] ath: Chip reset failed
Nov 20 09:04:11 raspberrypi kernel: [44753.645001] ath: Unable to reset channel (2462 Mhz) reset status -22
Nov 20 09:04:11 raspberrypi kernel: [44753.645018] ath: Unable to set channel
Nov 20 09:04:28 raspberrypi kernel: [44770.645557] ath: Unable to remove station entry for: f4:ec:xx:xx:xx:xx

syslog has LOTS of these messages:

Code: Select all

Nov 16 09:40:03 raspberrypi kernel: [ 4441.330947] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.330967] ifplugd         D c037a204     0  1687      1 0x00000000
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331033] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331098] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331141] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331173] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331211] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331234] INFO: task ifplugd:1705 blocked for more than 120 seconds.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331246] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331286] ifplugd         D c037a204     0  1705      1 0x00000000
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331329] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331359] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331391] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331420] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331448] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331472] INFO: task ntpd:2182 blocked for more than 120 seconds.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331484] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331497] ntpd            D c037a204     0  2182      1 0x00000001
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331561] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331592] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d81c0>] (dev_ioctl+0x4e4/0x864)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331623] [<c02d81c0>] (dev_ioctl+0x4e4/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331653] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331683] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331704] INFO: task smbd:2271 blocked for more than 120 seconds.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331715] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331729] smbd            D c037a204     0  2271      1 0x00000000
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331766] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331828] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02e37f4>] (rtnetlink_rcv+0xc/0x24)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331867] [<c02e37f4>] (rtnetlink_rcv+0xc/0x24) from [<c02f5520>] (netlink_unicast+0x2b0/0x308)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331900] [<c02f5520>] (netlink_unicast+0x2b0/0x308) from [<c02f5848>] (netlink_sendmsg+0x230/0x298)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331937] [<c02f5848>] (netlink_sendmsg+0x230/0x298) from [<c02c2988>] (sock_sendmsg+0x9c/0xbc)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.331970] [<c02c2988>] (sock_sendmsg+0x9c/0xbc) from [<c02c4474>] (sys_sendto+0xc0/0xfc)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.332003] [<c02c4474>] (sys_sendto+0xc0/0xfc) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 16 09:40:03 raspberrypi kernel: [ 4441.332068] INFO: task ip:3265 blocked for more than 120 seconds.

Raspbian is up-to date, with latest firmware.
I've tried increasing vm.min_free_kbytes in /etc/sysctl.conf as suggested in various guides.
Dongle is connected to usb hub powered by 2.5A adapter, so it shouldn't be power problem.
Please suggest, what else can be done.

[anath3ma]

Bump.

I crash every 4-8hrs.
Except I have a ralink 5370.
Many bins block, not just sudo. Most notably for me, login, iwconfig, and ifconfig all block once i start seeing the stack dumps in syslog.

Most but not all processes seem to be stuck in ret_fast_syscall.

I have a 3A power supply, and have even used pivot_root to a usb disk to rule out the SD card. It failed.

It could be coincidence however, over 24+hrs i have never crashed when i have a monitor plugged in and on.

I am assuming some call is stuck in a kernel mutex. If this sounds reasonable, how do i figure out which one it is?

Thanks..

Sample syslog:

Code: Select all

Nov 29 15:22:13 raspberrypi kernel: [29402.130850] INFO: task ifplugd:1620 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.130888] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.130906] ifplugd         D c037a204     0  1620      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.130970] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.131019] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 29 15:22:13 raspberrypi kernel: [29402.131059] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:22:13 raspberrypi kernel: [29402.131090] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:22:13 raspberrypi kernel: [29402.131129] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.131163] INFO: task ifplugd:1630 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.131176] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.131190] ifplugd         D c037a204     0  1630      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.131226] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.131274] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 29 15:22:13 raspberrypi kernel: [29402.131307] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:22:13 raspberrypi kernel: [29402.131336] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:22:13 raspberrypi kernel: [29402.131368] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.131398] INFO: task ifplugd:1638 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.131411] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.131425] ifplugd         D c037a204     0  1638      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.131463] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.131494] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 29 15:22:13 raspberrypi kernel: [29402.131535] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:22:13 raspberrypi kernel: [29402.131566] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:22:13 raspberrypi kernel: [29402.131596] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.131627] INFO: task ifplugd:1656 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.131641] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.131655] ifplugd         D c037a204     0  1656      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.131692] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.131721] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 29 15:22:13 raspberrypi kernel: [29402.131763] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:22:13 raspberrypi kernel: [29402.131793] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:22:13 raspberrypi kernel: [29402.131823] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.131847] INFO: task cupsd:2330 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.131858] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.131882] cupsd           D c037a204     0  2330      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.131920] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.131964] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02e37f4>] (rtnetlink_rcv+0xc/0x24)
Nov 29 15:22:13 raspberrypi kernel: [29402.132003] [<c02e37f4>] (rtnetlink_rcv+0xc/0x24) from [<c02f5520>] (netlink_unicast+0x2b0/0x308)
Nov 29 15:22:13 raspberrypi kernel: [29402.132047] [<c02f5520>] (netlink_unicast+0x2b0/0x308) from [<c02f5848>] (netlink_sendmsg+0x230/0x298)
Nov 29 15:22:13 raspberrypi kernel: [29402.132084] [<c02f5848>] (netlink_sendmsg+0x230/0x298) from [<c02c2988>] (sock_sendmsg+0x9c/0xbc)
Nov 29 15:22:13 raspberrypi kernel: [29402.132118] [<c02c2988>] (sock_sendmsg+0x9c/0xbc) from [<c02c4474>] (sys_sendto+0xc0/0xfc)
Nov 29 15:22:13 raspberrypi kernel: [29402.132162] [<c02c4474>] (sys_sendto+0xc0/0xfc) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.132189] INFO: task ifplugd:2574 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.132202] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.132215] ifplugd         D c037a204     0  2574      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.132263] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.132294] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 29 15:22:13 raspberrypi kernel: [29402.132327] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:22:13 raspberrypi kernel: [29402.132357] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:22:13 raspberrypi kernel: [29402.132398] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.132420] INFO: task hostapd:2577 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.132432] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.132445] hostapd         D c037a204     0  2577      1 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.132480] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.132717] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<bf00fb68>] (nl80211_pre_doit+0x114/0x16c [cfg80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.132876] [<bf00fb68>] (nl80211_pre_doit+0x114/0x16c [cfg80211]) from [<c02f6724>] (genl_rcv_msg+0x208/0x258)
Nov 29 15:22:13 raspberrypi kernel: [29402.132925] [<c02f6724>] (genl_rcv_msg+0x208/0x258) from [<c02f5b40>] (netlink_rcv_skb+0xac/0xc0)
Nov 29 15:22:13 raspberrypi kernel: [29402.132956] [<c02f5b40>] (netlink_rcv_skb+0xac/0xc0) from [<c02f6510>] (genl_rcv+0x18/0x24)
Nov 29 15:22:13 raspberrypi kernel: [29402.132984] [<c02f6510>] (genl_rcv+0x18/0x24) from [<c02f5520>] (netlink_unicast+0x2b0/0x308)
Nov 29 15:22:13 raspberrypi kernel: [29402.133025] [<c02f5520>] (netlink_unicast+0x2b0/0x308) from [<c02f5848>] (netlink_sendmsg+0x230/0x298)
Nov 29 15:22:13 raspberrypi kernel: [29402.133059] [<c02f5848>] (netlink_sendmsg+0x230/0x298) from [<c02c2988>] (sock_sendmsg+0x9c/0xbc)
Nov 29 15:22:13 raspberrypi kernel: [29402.133088] [<c02c2988>] (sock_sendmsg+0x9c/0xbc) from [<c02c2d70>] (__sys_sendmsg+0x2d4/0x2f0)
Nov 29 15:22:13 raspberrypi kernel: [29402.133121] [<c02c2d70>] (__sys_sendmsg+0x2d4/0x2f0) from [<c02c47d8>] (sys_sendmsg+0x3c/0x68)
Nov 29 15:22:13 raspberrypi kernel: [29402.133165] [<c02c47d8>] (sys_sendmsg+0x3c/0x68) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:13 raspberrypi kernel: [29402.133225] INFO: task kworker/0:0:18460 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.133249] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.133265] kworker/0:0     D c037a204     0 18460      2 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.133308] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.133348] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02e5918>] (linkwatch_event+0x8/0x34)
Nov 29 15:22:13 raspberrypi kernel: [29402.133411] [<c02e5918>] (linkwatch_event+0x8/0x34) from [<c003da30>] (process_one_work+0x134/0x38c)
Nov 29 15:22:13 raspberrypi kernel: [29402.133447] [<c003da30>] (process_one_work+0x134/0x38c) from [<c003e4a4>] (worker_thread+0x1a0/0x354)
Nov 29 15:22:13 raspberrypi kernel: [29402.133484] [<c003e4a4>] (worker_thread+0x1a0/0x354) from [<c0042e3c>] (kthread+0x84/0x8c)
Nov 29 15:22:13 raspberrypi kernel: [29402.133533] [<c0042e3c>] (kthread+0x84/0x8c) from [<c000e930>] (kernel_thread_exit+0x0/0x8)
Nov 29 15:22:13 raspberrypi kernel: [29402.133558] INFO: task ifconfig:27163 blocked for more than 120 seconds.
Nov 29 15:22:13 raspberrypi kernel: [29402.133571] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:22:13 raspberrypi kernel: [29402.133585] ifconfig        D c037a204     0 27163  27159 0x00000000
Nov 29 15:22:13 raspberrypi kernel: [29402.133624] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:22:13 raspberrypi kernel: [29402.133697] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<bf138074>] (rt2x00usb_vendor_request_buff+0x2c/0xb0 [rt2x00usb])
Nov 29 15:22:13 raspberrypi kernel: [29402.133766] [<bf138074>] (rt2x00usb_vendor_request_buff+0x2c/0xb0 [rt2x00usb]) from [<bf15f030>] (rt2x00usb_register_read+0x30/0x40 [rt2800usb])
Nov 29 15:22:13 raspberrypi kernel: [29402.133871] [<bf15f030>] (rt2x00usb_register_read+0x30/0x40 [rt2800usb]) from [<bf149d20>] (rt2800_conf_tx+0x78/0x23c [rt2800lib])
Nov 29 15:22:13 raspberrypi kernel: [29402.134196] [<bf149d20>] (rt2800_conf_tx+0x78/0x23c [rt2800lib]) from [<bf097be8>] (ieee80211_set_wmm_default+0x110/0x1a4 [mac80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.134530] [<bf097be8>] (ieee80211_set_wmm_default+0x110/0x1a4 [mac80211]) from [<bf082d78>] (ieee80211_set_disassoc+0x110/0x218 [mac80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.134820] [<bf082d78>] (ieee80211_set_disassoc+0x110/0x218 [mac80211]) from [<bf0865fc>] (ieee80211_mgd_deauth+0x23c/0x298 [mac80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.135197] [<bf0865fc>] (ieee80211_mgd_deauth+0x23c/0x298 [mac80211]) from [<bf01d3b8>] (__cfg80211_mlme_deauth+0xec/0x114 [cfg80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.135544] [<bf01d3b8>] (__cfg80211_mlme_deauth+0xec/0x114 [cfg80211]) from [<bf020238>] (__cfg80211_disconnect+0xc4/0x18c [cfg80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.135826] [<bf020238>] (__cfg80211_disconnect+0xc4/0x18c [cfg80211]) from [<bf007448>] (cfg80211_netdev_notifier_call+0x430/0x538 [cfg80211])
Nov 29 15:22:13 raspberrypi kernel: [29402.136001] [<bf007448>] (cfg80211_netdev_notifier_call+0x430/0x538 [cfg80211]) from [<c037e380>] (notifier_call_chain+0x44/0x84)
Nov 29 15:22:13 raspberrypi kernel: [29402.136063] [<c037e380>] (notifier_call_chain+0x44/0x84) from [<c00482d0>] (raw_notifier_call_chain+0x18/0x20)
Nov 29 15:22:13 raspberrypi kernel: [29402.136113] [<c00482d0>] (raw_notifier_call_chain+0x18/0x20) from [<c02d3c28>] (__dev_close_many+0x30/0xd0)
Nov 29 15:22:13 raspberrypi kernel: [29402.136169] [<c02d3c28>] (__dev_close_many+0x30/0xd0) from [<c02d3cf0>] (__dev_close+0x28/0x3c)
Nov 29 15:22:13 raspberrypi kernel: [29402.136203] [<c02d3cf0>] (__dev_close+0x28/0x3c) from [<c02d784c>] (__dev_change_flags+0x78/0x13c)
Nov 29 15:22:13 raspberrypi kernel: [29402.136232] [<c02d784c>] (__dev_change_flags+0x78/0x13c) from [<c02d797c>] (dev_change_flags+0x10/0x48)
Nov 29 15:22:13 raspberrypi kernel: [29402.136285] [<c02d797c>] (dev_change_flags+0x10/0x48) from [<c032a484>] (devinet_ioctl+0x668/0x794)
Nov 29 15:22:13 raspberrypi kernel: [29402.136324] [<c032a484>] (devinet_ioctl+0x668/0x794) from [<c02c2380>] (sock_ioctl+0x70/0x26c)
Nov 29 15:22:13 raspberrypi kernel: [29402.136359] [<c02c2380>] (sock_ioctl+0x70/0x26c) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:22:13 raspberrypi kernel: [29402.136402] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:22:13 raspberrypi kernel: [29402.136439] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)
Nov 29 15:22:34 raspberrypi kernel: [29423.281541] phy0 -> rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x101c with error -110.
Nov 29 15:23:24 raspberrypi kernel: [29473.283143] phy0 -> rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x101c with error -110.
Nov 29 15:24:13 raspberrypi kernel: [29522.134719] INFO: task ifplugd:1620 blocked for more than 120 seconds.
Nov 29 15:24:13 raspberrypi kernel: [29522.134741] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 15:24:13 raspberrypi kernel: [29522.134758] ifplugd         D c037a204     0  1620      1 0x00000000
Nov 29 15:24:13 raspberrypi kernel: [29522.134837] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Nov 29 15:24:13 raspberrypi kernel: [29522.134873] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Nov 29 15:24:13 raspberrypi kernel: [29522.134926] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Nov 29 15:24:13 raspberrypi kernel: [29522.134960] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Nov 29 15:24:13 raspberrypi kernel: [29522.134998] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)

Context info:
tvservice -s
state: HPD low|HDMI mode|composite off (0x120009), 1920x1080 @ 60Hz, progressive

256mb pi

uname -a
Linux raspberrypi 3.2.27+ #250 PREEMPT Thu Oct 18 19:03:02 BST 2012 armv6l GNU/Linux

Bus 001 Device 009: ID 148f:5370 Ralink Technology, Corp. RT5370 Wireless Adapter

[the_summer]

Hi,

As I already wrote in the USB redux thread, I have the same problemm with a TL-821N.
Could it also be that it is a problem with the ath-driver? Has anyone tried of the problem is solved when using a kernel from the 3.6-branch?

[gabone]

Hi,

I seem to have the same problem. I have a TP-Link TL-WN722N on a Raspberry Pi model B. The TP-Link is connected to the Pi via a powered hub that has a 2A power source. After a couple of hours the Pi just hangs with these messages:

Dec 28 13:53:19 raspberrypi kernel: [12841.543655] INFO: task ifplugd:1483 blocked for more than 120 seconds.
Dec 28 13:53:19 raspberrypi kernel: [12841.543692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 28 13:53:19 raspberrypi kernel: [12841.543710] ifplugd D c037a204 0 1483 1 0x00000000
Dec 28 13:53:19 raspberrypi kernel: [12841.543776] [<c037a204>] (__schedule+0x2bc/0x568) from [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154)
Dec 28 13:53:19 raspberrypi kernel: [12841.543824] [<c037b720>] (__mutex_lock_slowpath+0xb8/0x154) from [<c02d80bc>] (dev_ioctl+0x3e0/0x864)
Dec 28 13:53:19 raspberrypi kernel: [12841.543864] [<c02d80bc>] (dev_ioctl+0x3e0/0x864) from [<c00c855c>] (do_vfs_ioctl+0x7c/0x578)
Dec 28 13:53:19 raspberrypi kernel: [12841.543896] [<c00c855c>] (do_vfs_ioctl+0x7c/0x578) from [<c00c8a8c>] (sys_ioctl+0x34/0x60)
Dec 28 13:53:19 raspberrypi kernel: [12841.543945] [<c00c8a8c>] (sys_ioctl+0x34/0x60) from [<c000d980>] (ret_fast_syscall+0x0/0x30)

Most of the time the Pi has high load over 0.5. After some time the load jumps over 1.0 to altmost 7.0 and after that it hangs. I have to unplug the Pi and power it up again to reboot it to regain access to it.

If you have any idea what could cause this, please share.

Thank you.
Gabriel

[gabone]

On second thought, it might be something else. I read several other posts that say that reading or writing to the SD card takes too much I/O. I am running squid and iptables on this Pi and I am using it as an access point router. It seems that squid uses the SD card as caching store also as logging. At the same time iptables was configured with logging but it had no limits to logged packets and it was filling the logs with too much text, thus writing to the SD card. Several hours later, after reading about these, and checking the I/Os with "iostat -mx 5", I decided to disable squid caching and logging, using it only as a proxy, and I also limited the iptables output. It seems that at the moment does not go over 0.3 load average and most of the time it stays under 0.1. Let's hope it stays that way.

Happy new year!

[gabone]

I was celebrating too early. While I managed to reduce the overall load on the Pi, it seems that the problem persists. I had to reboot 5 minutes ago, because the Pi hanged due to escalating cpu load over 7, until it did not respond to commands. So, if anyone has any ideas, I would really appreciate them.

Thank you.

[gabone]

A week later I discovered that he cause of the TL-WN722N disconnect problem is a 3G modem that I am using for connecting to internet. Every couple of hours or more, I see in the logs:

Jan 5 04:26:30 raspberrypi kernel: [14347.970945] option: option_instat_callback: error -71
Jan 5 04:26:30 raspberrypi kernel: [14347.976952] option: option_instat_callback: error -71
Jan 5 04:26:30 raspberrypi kernel: [14347.982940] option: option_instat_callback: error -71
Jan 5 04:26:30 raspberrypi kernel: [14347.984395] hub 1-1:1.0: port 3 disabled by hub (EMI?), re-enabling...
Jan 5 04:26:30 raspberrypi kernel: [14347.984426] usb 1-1.3: USB disconnect, device number 17
Jan 5 04:26:30 raspberrypi kernel: [14347.984442] usb 1-1.3.1: USB disconnect, device number 18
Jan 5 04:26:30 raspberrypi kernel: [14347.984456] usb 1-1.3.1.2: USB disconnect, device number 24
Jan 5 04:26:30 raspberrypi kernel: [14347.985124] option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Jan 5 04:26:30 raspberrypi kernel: [14347.985223] option 1-1.3.1.2:1.0: device disconnected
Jan 5 04:26:30 raspberrypi kernel: [14347.988885] option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Jan 5 04:26:30 raspberrypi kernel: [14347.988953] option: option_instat_callback: error -71
Jan 5 04:26:30 raspberrypi kernel: [14347.989058] option 1-1.3.1.2:1.1: device disconnected
Jan 5 04:26:30 raspberrypi kernel: [14347.989626] option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Jan 5 04:26:30 raspberrypi kernel: [14347.989717] option 1-1.3.1.2:1.2: device disconnected
Jan 5 04:26:30 raspberrypi kernel: [14347.996038] usb 1-1.3.4: USB disconnect, device number 23
Jan 5 04:26:30 raspberrypi kernel: [14348.274838] usb 1-1.3: new high-speed USB device number 25 using dwc_otg
Jan 5 04:26:30 raspberrypi kernel: [14348.375888] usb 1-1.3: New USB device found, idVendor=1a40, idProduct=0101
Jan 5 04:26:30 raspberrypi kernel: [14348.375917] usb 1-1.3: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Jan 5 04:26:30 raspberrypi kernel: [14348.375934] usb 1-1.3: Product: USB 2.0 Hub
Jan 5 04:26:30 raspberrypi kernel: [14348.376861] hub 1-1.3:1.0: USB hub found
Jan 5 04:26:30 raspberrypi kernel: [14348.377125] hub 1-1.3:1.0: 4 ports detected

I read a couple of posts and some people say that it is a faulty modem, or some faulty implementation of the USB protocol. The problem is that it seems no one has found the solution.
My modem is connected via a 5m USB cable, and someone said that this would happen only when the modem is connected using a cable. He even said that he tried different cables, and it behaved the same. The thing is, I tried without the cable, and it seemed to be stable for a longer time.
I tried with two different modems (both are ZTE), but both of them have the same problem. I do not know what else to do. Some people said that these errors could not be reproduced on FreeBSD. I am pretty much stuck here. Probably the only solution is to stop using the 5 meter USB cable.

[NewPi]

Facing same issue, seems the RPi USB stack panics under high load.

[gabone]

I changed the cable between the Pi and the hub. It seemed to be a little thin. That made me think it is not shielded. I'm still not sure if it is or not, but I changed it anyway with a shorter cable from a SATA HDD enclosure that was a little thicker than the other one. Well, I have an uptime of 2 days and 11 hours and I had no USB disconnects, so it seems like the old cable had some EMI. Probably the kernel was right. The hub is made by Logilink and it is backpowering:

http://www.logilink.com/showproduct/UA0114.htm

[gabone]

After 5 days and a couple of hours it disconnected all the USB devices, logging the same errors. I'd say it's an improvement..

[ecocozza]

Any update on this?

I'm having the same issue. I have tried using both ZTE and Huawei modems along with the TL-WN722N wifi adapter.

I haven't tested with no cable to the 3G yet, am going to try that now.

I did get myself a multimeter though, and so far as I can tell the cable doesn't actually cause the voltage to drop.

Thanks,
-Eric

[maniaque]

Same problems, exactly. Waiting for approval of my forum post with the same adapter and same setup and same log entries.

[ecocozza]

Your post was approved: http://www.raspberrypi.org/phpBB3/viewtopic.php?t=51644

Looking at the original posters logs.... The logs you shared... and knowing my own personal setup, we are all trying to setup a WiFi hotspot using 3G and hostapd... I think hostapd may be the Achilles heel.... (I have switched out my both my 3G modem and my wifi adapters with completely different brands and the results are the same).

A friend suggested I see what happens in ad-hoc mode (no hostapd)... Worth a try I think, but going to take some time for me to figure out how to set it up.

[gabone]

Frankly, after a while, and after some kernel updates, my setup seems stable. The only thing that drops is my 3G connection from time to time, but the wifi interface is working fine.

[ecocozza]

Thanks for the update. Could you post your kernel version?

uname -r returns 3.6.11+ for me.

I'm running since last night in ad-hoc mode, and haven't frozen up yet.... Typically I last under 4 hours.
(Edit) I spike to soon... Pi froze up just now

[maniaque]

Well, I would try to use some other WiFi dongle, I think there is an issue with driver. Or I don't know.

But looks like the hostapd is innocent for now

[ecocozza]

Did you switch away from the TL-WN722N? If yes, what are you using now?

Thanks,

-Eric

[anath3ma]

Just a guess but I think the problem with infrastructure common to all the devices that have had these problems and not a specific driver. I have had the exact same issues since Nov '12 with a Ralink RT5370 & the TL-WN722N iirc is an atheros device. Such devices have a reputation for having rock solid drivers.

As a programmer, failing at a mutex is telling, but I haven't heard from anyone in charge of said kernel infrastructure. It is also safe to assume that if x86 linux users at large don't have similar issues, they have something to do with the rpi specifically. i.e. (Not the usb stack but perhaps the chip drivers/hardware/hostAP) I have also tried every permutation of power/timing/SDcard related changes i could think of and managed to delay a failure. I'm guessing most of what i did was just change kernel timing so the problem expressed itself less, but it was never fixed.

So, yeah. Target the people on the kernel end or those writing hostAP. I tried way back when I started having these issues, but no one seemed to express any interest.
Good luck!
m

[maniaque]

To Eric: nope, I haven't found the adapter yet, it is a little bit challenging for me, because I live in Russia, and our post service is very bad (you can wait for 2-3 weeks for international delivery) and the list of available hardware from local suppliers is rather short. So the process looks like this: I find the device with a specific driver, list the models, do the research, etc. I will write here about my future tests.

To m: thanks! I'm waiting for BeagleBone Black to arrive soon, but till now will try to do the same setup on BeagleBone, can share the results, if you are interested.

[anath3ma]

Another interesting test would be to set up a single wifi/3g device (i.e. NO hostap) and do something stressful with lots of ports like downloading a torrent (not just an http download) of a linux cd, deleting it, downloading again, repeat forever. Let that churn for a day or two and see where you are in the morning. This could build reasonable confidence to clear/indict hostap.

edit: Just reread the post where someone failed w adhoc. That said, i think it would still be interesting to see if you could stress a normal setup with one interface to the point where the mutex problem happened again.
m

[maniaque]

Yep, and by the way, other RPi with E398 Huawei LTE modem is looking rock solid for now, works in tandem with TP Link wireless AP, providing Internet ppp0 <-> eth0, still no issues.

[maniaque]

To m: you know, I've done such kind of tests, still nothing, rock solid. Scanning the logs, looks like the problem happens when a new device comes, or goes away, or doing something like going out of range.

The WiFi is the only thing having unpredictable behavior of second point, e.g. the user. IMHO this is the case.

[gabone]

Here is my uname -a:

Linux raspberrypi 3.6.11+ #474 PREEMPT

I got even 9 days uptime without any problem. Sometimes I have to reset the RPi because the 3G does not dial up anymore. I mean, it does not hang, it is still controllable, but the 3G dongle has to be reset somehow by rebooting the pi. I have a script that checks the 3G connection and redials, and if it is not able to reestablish the connection, then it reboots itself.

Seriously, after I changed my USB cable that connected the RPi to the USB hub, I stopped having problems with the RPi. It never hanged anymore. The system is so stable that it runs by itself for months without any intervention. At the moment I have more problems with the other Pi that hosts a CSI camera. It seem that after a while, 1-2 days, I receive some MMC messages in the logs, and hangs. I think it's something related to the SD card. The application is saving many images in the SD card and from time to time it hangs.

[anath3ma]

gabone: When it fails, can you still issue more system calls without bash hanging (like those invoked by ifconfig)? If so, you likely aren't having the mutex issue, but some other one related to your 3G driver/firmware.
I will try a new cable but as my hub was expensive/well regarded I have little hope. That said, I just updated raspbian and did a firmware update after letting the device atrophy on the windowsill for half a year. So, we will see if anything got solved.
M

[gabone]

Actually the pi does not hang anymore. Only the 3G dongle is not able to dial the ppp connection. I can still access the 3G dongle by AT commands. It is probably a problem with the 3G dongle, I have to reset the Pi to be able to establish the connection. Otherwise the pi is working just fine. The AP/hostapd is fine. I can connect to it, issue any command.

If you read my first couple of posts, you will see that I had the same mutex issue. After I changed the USB cable, it worked for a couple of days before it hanged. After that I did some more kernel updates and it does not hang anymore. At the moment I have an uptime of 1 day and 3 hours before the script restarted the pi to solve the 3G dialup problem. Before that I had 9 days without a restart.