maniaque
Posts: 10
Joined: Mon Mar 11, 2013 3:33 pm

USB WiFi (and other) issues

Fri Aug 02, 2013 6:47 pm

I've decided to publish the results of my experiments with Pi and WiFi, maybe they will be useful for someone. Sorry for my bad English, it's not my native language.

The original task was easy - create a LTE <-> WiFi router with Pi, using USB powered hub. Looks simple, huh?

Here is the hardware:
  • RPi, rev. B
    D-Link DUB-H7 USB powered HUB
    Huawei E398 LTE modem
    TP-Link TL-WN722N using 3 meters USB cable (later on this subject)
First, let me tell more about the task - I was creating a WiFi free-for-all hotstop at a public place, so the dongles without antenna were not good in providing the coverage I needed. That is why I have used TL-WN722N - it has an antenna, and I have used the USB cable to put its antenna the right way to have a better coverage.

Now was the time to configure the software. I have started with Raspbian, but the image I've used was not clean and it was rather old, so very fast I've switched to Arch Linux.

The setup was simple: hostapd as WiFi provider, udhcpd as DHCP-server, iptables as a NAT provider, wvdial as dialer, custom-written script to provide usb_modeswitch, control over wvdial and wget script to "ping" my private web-page (for me it was useful to have a tail of access log to have a heartbeat).

The first launch was not luckily enough – one day and then the heartbeat died. The everything.log gave me the following:

Code: Select all

Jul 21 03:54:52 alarmpi kernel: [174130.696823] INFO: task kworker/0:1:17809 blocked for more than 120 seconds.
Jul 21 03:54:52 alarmpi kernel: [174130.784620] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 21 03:54:52 alarmpi kernel: [174130.886851] kworker/0:1     D c055ec24     0 17809      2 0x00000000
Jul 21 03:54:52 alarmpi kernel: [174130.886960] [<c055ec24>] (__schedule+0x2ec/0x638) from [<c055d9bc>] (schedule_timeout+0x16c/0x248)
Jul 21 03:54:52 alarmpi kernel: [174130.887043] [<c055d9bc>] (schedule_timeout+0x16c/0x248) from [<c055f16c>] (wait_for_common+0x108/0x190)
Jul 21 03:54:52 alarmpi kernel: [174130.887117] [<c055f16c>] (wait_for_common+0x108/0x190) from [<c00424e8>] (kthread_create_on_node+0x88/0xf8)
Jul 21 03:54:52 alarmpi kernel: [174130.887158] [<c00424e8>] (kthread_create_on_node+0x88/0xf8) from [<c003af04>] (create_worker+0xfc/0x214)
Jul 21 03:54:52 alarmpi kernel: [174130.887188] [<c003af04>] (create_worker+0xfc/0x214) from [<c003b708>] (manage_workers+0x200/0x324)
Jul 21 03:54:52 alarmpi kernel: [174130.887218] [<c003b708>] (manage_workers+0x200/0x324) from [<c003cfe4>] (worker_thread+0x2a8/0x488)
Jul 21 03:54:52 alarmpi kernel: [174130.887243] [<c003cfe4>] (worker_thread+0x2a8/0x488) from [<c00422f0>] (kthread+0x84/0x90)
Jul 21 03:57:11 alarmpi kernel: [174130.887278] [<c00422f0>] (kthread+0x84/0x90) from [<c000eac0>] (kernel_thread_exit+0x0/0x8)
Well, it looks like we have a problem with some cron jobs it was about to do something and it hung. Damn, restart it. Start it over. One day without hangs and again.

Code: Select all

Jul 22 07:18:37 alarmpi kernel: [53044.516054] INFO: task ifplugd:142 blocked for more than 120 seconds.
Jul 22 07:18:37 alarmpi kernel: [53044.539382] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 22 07:18:37 alarmpi kernel: [53044.564841] ifplugd         D c055ec24     0   142      1 0x00000000
Jul 22 07:18:37 alarmpi kernel: [53044.564950] [<c055ec24>] (__schedule+0x2ec/0x638) from [<c055f640>] (schedule_preempt_disabled+0x14/0x20)
Jul 22 07:18:37 alarmpi kernel: [53044.564991] [<c055f640>] (schedule_preempt_disabled+0x14/0x20) from [<c055e218>] (__mutex_lock_slowpath+0xa0/0x124)
Jul 22 07:18:37 alarmpi kernel: [53044.565029] [<c055e218>] (__mutex_lock_slowpath+0xa0/0x124) from [<c04adfa0>] (dev_ioctl+0x3e0/0x85c)
Jul 22 07:18:37 alarmpi kernel: [53044.565066] [<c04adfa0>] (dev_ioctl+0x3e0/0x85c) from [<c00ff27c>] (do_vfs_ioctl+0x80/0x5c8)
Jul 22 07:18:37 alarmpi kernel: [53044.565094] [<c00ff27c>] (do_vfs_ioctl+0x80/0x5c8) from [<c00ff830>] (sys_ioctl+0x6c/0x7c)
Jul 22 07:18:37 alarmpi kernel: [53044.565128] [<c00ff830>] (sys_ioctl+0x6c/0x7c) from [<c000db20>] (ret_fast_syscall+0x0/0x30)
Well, looks like we have something strange with our network interface, but wait, eth0 is not used, so looks like wlan0 is not very good. Maybe we should not use USB-cable? But the hub is powered. Okay, the cable removed and WiFi dongle is plugged right into the hub. Go!

Funny thing was the complete silence over eth0 – it was not just working at all. Does it looks like something was happening with root USB hub? Dunno.

Code: Select all

Jul 24 14:04:51 alarmpi kernel: [78246.011806] INFO: task ifplugd:154 blocked for more than 120 seconds.
Jul 24 14:04:51 alarmpi kernel: [78246.034723] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 24 14:04:51 alarmpi kernel: [78246.060229] ifplugd         D c055ec24     0   154      1 0x00000000
Jul 24 14:04:51 alarmpi kernel: [78246.060334] [<c055ec24>] (__schedule+0x2ec/0x638) from [<c055f640>] (schedule_preempt_disabled+0x14/0x20)
Jul 24 14:04:51 alarmpi kernel: [78246.060374] [<c055f640>] (schedule_preempt_disabled+0x14/0x20) from [<c055e218>] (__mutex_lock_slowpath+0xa0/0x124)
Jul 24 14:04:51 alarmpi kernel: [78246.060411] [<c055e218>] (__mutex_lock_slowpath+0xa0/0x124) from [<c04adfa0>] (dev_ioctl+0x3e0/0x85c)
Jul 24 14:04:51 alarmpi kernel: [78246.060450] [<c04adfa0>] (dev_ioctl+0x3e0/0x85c) from [<c00ff27c>] (do_vfs_ioctl+0x80/0x5c8)
Jul 24 14:04:51 alarmpi kernel: [78246.060478] [<c00ff27c>] (do_vfs_ioctl+0x80/0x5c8) from [<c00ff830>] (sys_ioctl+0x6c/0x7c)
Jul 24 14:04:51 alarmpi kernel: [78246.060512] [<c00ff830>] (sys_ioctl+0x6c/0x7c) from [<c000db20>] (ret_fast_syscall+0x0/0x30)
Erm, looks like the cable was not the case. Damn. Well, we have two USB-devices, modem and WiFi dongle, so maybe it was not the WiFi dongle to blame. Let us have a look.

But before let us try one more thing. Okay, we could use this in sysctl.conf

Code: Select all

# Reboot 5 seconds after panic
kernel.panic = 5

# Panic if a hung task was found
kernel.hung_task_panic = 1

# Setup timeout for hung task to 300 seconds
kernel.hung_task_timeout_secs = 300
Okay, looks reasonable, but gives us nothing. Even in everything.log. Just silence and disappearance of the WiFi-network.

I bought two RPi’s, so I have done the job separation – one Pi was with LTE-modem, one with WiFi-dongle, the connection between was done via Ethernet cable. I have called this configuration “the tandem”. Go!

Eeeeeek, no luck – WiFi-enabled Pi was dead again.

Code: Select all

Jul 31 14:40:01 dima kernel: [361879.039884] kworker/u:0: page allocation failure: order:0, mode:0x20
Jul 31 14:40:01 dima kernel: [361879.039973] [<c0013b84>] (unwind_backtrace+0x0/0xf0) from [<c00b4360>] (warn_alloc_failed+0xd0/0x118)
Jul 31 14:40:01 dima kernel: [361879.040016] [<c00b4360>] (warn_alloc_failed+0xd0/0x118) from [<c00b6a50>] (__alloc_pages_nodemask+0x53c/0x724)
Jul 31 14:40:01 dima kernel: [361879.040055] [<c00b6a50>] (__alloc_pages_nodemask+0x53c/0x724) from [<c00e3184>] (cache_alloc_refill+0x32c/0x6a0)
Jul 31 14:40:01 dima kernel: [361879.040084] [<c00e3184>] (cache_alloc_refill+0x32c/0x6a0) from [<c00e2d94>] (kmem_cache_alloc+0xb8/0x17c)
Jul 31 14:40:01 dima kernel: [361879.040124] [<c00e2d94>] (kmem_cache_alloc+0xb8/0x17c) from [<c04a0f50>] (__alloc_skb+0x44/0x158)
Jul 31 14:40:01 dima kernel: [361879.040220] [<c04a0f50>] (__alloc_skb+0x44/0x158) from [<bf185a18>] (ath9k_wmi_cmd+0x48/0x1b0 [ath9k_htc])
Jul 31 14:40:01 dima kernel: [361879.040317] [<bf185a18>] (ath9k_wmi_cmd+0x48/0x1b0 [ath9k_htc]) from [<bf18ae78>] (ath9k_regwrite+0x5c/0xfc [ath9k_htc])
Jul 31 14:40:01 dima kernel: [361879.040411] [<bf18ae78>] (ath9k_regwrite+0x5c/0xfc [ath9k_htc]) from [<bf18af48>] (ath9k_reg_rmw+0x30/0x38 [ath9k_htc])
Jul 31 14:40:01 dima kernel: [361879.040677] [<bf18af48>] (ath9k_reg_rmw+0x30/0x38 [ath9k_htc]) from [<bf118048>] (ath9k_hw_set_gpio+0x54/0x94 [ath9k_hw])
Jul 31 14:54:16 dima kernel: [361879.040828] [<bf118048>] (ath9k_hw_set_gpio+0x54/0x94 [ath9k_hw]) from [<c003c7dc>] (process_one_work+0x160/0x4f0)
Jul 31 14:54:16 dima kernel: [361879.040861] [<c003c7dc>] (process_one_work+0x160/0x4f0) from [<c003ce88>] (worker_thread+0x14c/0x488)
Jul 31 14:54:16 dima kernel: [361879.040893] [<c003ce88>] (worker_thread+0x14c/0x488) from [<c00422f0>] (kthread+0x84/0x90)
Jul 31 14:54:16 dima kernel: [361879.040931] [<c00422f0>] (kthread+0x84/0x90) from [<c000eac0>] (kernel_thread_exit+0x0/0x8)
So I’m out of ideas. Looks like I would have a problem in creating a WiFi enabled Pi with antenna for better coverage. Any ideas, anyone?

maniaque
Posts: 10
Joined: Mon Mar 11, 2013 3:33 pm

Re: USB WiFi (and other) issues

Mon Aug 05, 2013 5:35 pm

Okay, I am posting the follow up (as promised), I'll duplicate it in my thread too.

Therefore, I've build the installation with BeagleBone using ArchLinux, same D-Link powered hub, and made a configuration (hostapd, iptables), installed my custom script for keeping up the connection.

Afterwards, I was changing the hostname, so I have decided to make a reboot, and issued the "reboot" command. Moreover, WiFi dongle has disappeared. everything.log showed the following:

Code: Select all

Aug  5 09:34:24 igor kernel: [   11.903593] usb 1-1.1.1: khubd timed out on ep0in len=0/64
Aug  5 09:34:24 igor kernel: [   16.903574] usb 1-1.1.1: khubd timed out on ep0in len=0/64
Aug  5 09:34:24 igor kernel: [   16.970155] usb 1-1.1.1: device descriptor read/64, error -110
Aug  5 09:34:24 igor kernel: [   22.079477] usb 1-1.1.1: khubd timed out on ep0in len=0/64
and

Code: Select all

Aug  5 09:35:25 igor kernel: [   83.425041] usb 1-1.1.1: khubd timed out on ep0out len=0/0
Aug  5 09:35:30 igor kernel: [   83.628146] usb 1-1.1.1: device not accepting address 7, error -110
Aug  5 09:35:30 igor kernel: [   83.635084] hub 1-1.1:1.0: unable to enumerate USB device on port 1
Aug  5 09:35:30 igor kernel: [   83.641966] hub 1-1.1:1.0: state 7 ports 4 chg 0000 evt 0002
Aug  5 09:35:30 igor kernel: [   83.646027] hub 1-1.1:1.0: hub_suspend
Aug  5 09:35:30 igor kernel: [   83.646542] usb 1-1.1: usb auto-suspend, wakeup 1
Aug  5 09:35:30 igor kernel: [   83.660432] hub 1-1:1.0: hub_suspend
Aug  5 09:35:30 igor kernel: [   83.663008] usb 1-1: usb auto-suspend, wakeup 1
Aug  5 09:35:30 igor kernel: [   83.674986] hub 1-0:1.0: hub_suspend
Aug  5 09:35:30 igor kernel: [   83.675014] usb usb1: bus auto-suspend, wakeup 1
Aug  5 09:35:25 igor systemd-udevd[101]: worker [113] terminated by signal 9 (Killed) 
Looks like we have problems with USB device on reboot. The problem was strange: rebooting the BeagleBone did not helped, only complete poweroff of HUB and BeagleBone did helped. I have created a "rebooter" service - its task was to reboot the box 2 minutes after boot and started waiting.

And I had the issue repeated – completely lost WiFi dongle. So, what to do next?

Return to “Troubleshooting”