whezzy + hostapd + ath9k = random fail
Hi all. I got a problem with my soft AP.
I got an old PC running as router which has 3 NIC and 1 wifi PCI card
TP-Link TL-WN751ND. This box runs Debian Wheezy, hostapd, dhcpd etc.
The problem is that AP randomly gets unreachable for the clients while
hostapd is running and its interface is up. In fact, this router had
been working in 6 day w/o any problems since I set it up until the
yesterday.
What interfaces I have exactly:
--------------------------------------------
eth0 is down (3Com)
eth1 gets IP from ISP DHCP (Realtek)
eth2 takes IP for my LAN over DHCPD
ppp0 - it's an ISP VPN over PPTP
Configuration:
-------------------
$ cat /etc/debian_version
wheezy/sid
$ uname -r
3.2.0-2-686-pae
dpkg -l | grep linux-image
ii linux-image-2.6-686 3.2+44
Linux for modern PCs (dummy package)
ii linux-image-3.2.0-2-686-pae 3.2.17-1
Linux 3.2 for modern PCs
ii linux-image-686-pae 3.2+44
Linux for modern PCs (meta-package)
$ hostapd -v
hostapd v1.0
User space daemon for IEEE 802.11 AP management,
IEEE 802.1X/WPA/WPA2/EAP/RADIUS Authenticator
Copyright (c) 2002-2010, Jouni Malinen <j@w1.fi> and contributors
$ lspci
00:00.0 Host bridge: Intel Corporation 82810E DC-133 (GMCH) Graphics
Memory Controller Hub (rev 03)
00:01.0 VGA compatible controller: Intel Corporation 82810E DC-133
(CGC) Chipset Graphics Controller (rev 03)
00:1e.0 PCI bridge: Intel Corporation 82801AA PCI Bridge (rev 02)
00:1f.0 ISA bridge: Intel Corporation 82801AA ISA Bridge (LPC) (rev 02)
00:1f.1 IDE interface: Intel Corporation 82801AA IDE Controller (rev 02)
00:1f.2 USB controller: Intel Corporation 82801AA USB Controller (rev 02)
00:1f.3 SMBus: Intel Corporation 82801AA SMBus Controller (rev 02)
01:07.0 Multimedia audio controller: Ensoniq ES1371 [AudioPCI-97] (rev 06)
01:08.0 Network controller: Atheros Communications Inc. AR9227
Wireless Network Adapter (rev 01)
01:09.0 Ethernet controller: Sundance Technology Inc / IC Plus Corp IC
Plus IP100A Integrated 10/100 Ethernet MAC + PHY (rev 31)
01:0a.0 Ethernet controller: Realtek Semiconductor Co., Ltd.
RTL-8139/8139C/8139C+ (rev 10)
01:0b.0 Ethernet controller: 3Com Corporation 3c905 100BaseTX [Boomerang]
eth1 Link encap:Ethernet HWaddr 00:60:97:d8:dd:ea
inet addr:192.168.120.184 Bcast:192.168.120.255 Mask:255.255.255.0
inet6 addr: fe80::260:97ff:fed8:ddea/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:431713 errors:74 dropped:682 overruns:59 frame:0
TX packets:171981 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:283031893 (269.9 MiB) TX bytes:21389936 (20.3 MiB)
Interrupt:10 Base address:0xd800
eth2 Link encap:Ethernet HWaddr 14:da:e9:a7:21:33
inet addr:192.168.1.1 Bcast:192.168.1.255 Mask:255.255.255.0
inet6 addr: fe80::16da:e9ff:fea7:2133/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:276872 errors:0 dropped:0 overruns:0 frame:0
TX packets:338010 errors:1 dropped:30 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:23357782 (22.2 MiB) TX bytes:278728804 (265.8 MiB)
Interrupt:11 Base address:0xdc00
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
inet6 addr: ::1/128 Scope:Host
UP LOOPBACK RUNNING MTU:16436 Metric:1
RX packets:4 errors:0 dropped:0 overruns:0 frame:0
TX packets:4 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:436 (436.0 B) TX bytes:436 (436.0 B)
mon.wlan0 Link encap:UNSPEC HWaddr
B0-48-7A-E3-AE-0F-00-00-00-00-00-00-00-00-00-00
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)
ppp0 Link encap:Point-to-Point Protocol
inet addr:80.242.96.16 P-t-P:195.66.139.23 Mask:255.255.255.255
UP POINTOPOINT RUNNING NOARP MULTICAST MTU:1400 Metric:1
RX packets:225471 errors:0 dropped:0 overruns:0 frame:0
TX packets:142471 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:3
RX bytes:252918981 (241.2 MiB) TX bytes:11957326 (11.4 MiB)
wlan0 Link encap:Ethernet HWaddr b0:48:7a:e3:ae:0f
inet addr:192.168.2.1 Bcast:192.168.2.255 Mask:255.255.255.0
inet6 addr: fe80::b248:7aff:fee3:ae0f/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:252 errors:0 dropped:0 overruns:0 frame:0
TX packets:420 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:31491 (30.7 KiB) TX bytes:240068 (234.4 KiB)
$ iwconfig
wlan0 IEEE 802.11bgn Mode:Master Frequency:2.437 GHz Tx-Power=13 dBm
Retry long limit:7 RTS thr:off Fragment thr:off
Power Management:on
mon.wlan0 IEEE 802.11bgn Mode:Monitor Tx-Power=13 dBm
Retry long limit:7 RTS thr:off Fragment thr:off
Power Management:on
The content of my system logs:
----------------------------------------------
This part of /var/log/messages caught my attention:
May 26 03:19:01 debian kernel: [10947.008116] ------------[ cut here
]------------
May 26 03:19:01 debian kernel: [10947.008167] WARNING: at
/build/buildd-linux-2.6_3.2.17-1-i386-rPdRhH/linux-2.6-3.2.17/debian/build/so
urce_i386_none/net/sched/sch_generic.c:255 dev_watchdog+0xb1/0x104()
May 26 03:19:01 debian kernel: [10947.008181] Hardware name:
May 26 03:19:01 debian kernel: [10947.008190] NETDEV WATCHDOG: eth2
(sundance): transmit queue 0 timed out
May 26 03:19:01 debian kernel: [10947.008199] Modules linked in:
cryptd aes_i586 aes_generic ppp_async crc_ccitt ppp_generic slhc ipt_M
ASQUERADE xt_TCPMSS xt_limit xt_pkttype ipt_REJECT xt_tcpudp xt_state
ipt_LOG iptable_mangle iptable_nat iptable_filter nf_conntrack_ir
c nf_nat_ftp nf_conntrack_ftp nf_nat nf_conntrack_ipv4 nf_defrag_ipv4
nf_conntrack ip_tables x_tables 8021q garp stp loop arc4 ath9k at
h9k_common ath9k_hw snd_ens1371 ath snd_ac97_codec mac80211
snd_rawmidi snd_seq_device cfg80211 snd_pcm evdev snd_page_alloc
snd_timer rfkill snd soundcore ac97_bus pcspkr serio_raw i2c_i801
gameport i2c_core iTCO_wdt iTCO_vendor_support rng_core shpchp
parport_pc parport processor button thermal_sys ext4 crc16 jbd2
mbcache dm_mod sr_mod sd_mod cdrom crc_t10dif ata_generic ata_piix
libata 8139too uhci_hcd ehci_hcd scsi_mod usbcore usb_common 3c59x
8139cp floppy sundance mii [last unloaded: scsi_wait_scan]
May 26 03:19:01 debian kernel: [10947.008476] Pid: 1705, comm: rs:main
Q:Reg Not tainted 3.2.0-2-686-pae #1
May 26 03:19:01 debian kernel: [10947.008486] Call Trace:
May 26 03:19:01 debian kernel: [10947.008513] [<c103845c>] ?
warn_slowpath_common+0x68/0x79
May 26 03:19:01 debian kernel: [10947.008528] [<c1231444>] ?
dev_watchdog+0xb1/0x104
May 26 03:19:01 debian kernel: [10947.008545] [<c10384d5>] ?
warn_slowpath_fmt+0x29/0x2d
May 26 03:19:01 debian kernel: [10947.008560] [<c1231444>] ?
dev_watchdog+0xb1/0x104
May 26 03:19:01 debian kernel: [10947.008613] [<c103ce5d>] ?
local_bh_enable+0x2/0x2
May 26 03:19:01 debian kernel: [10947.008641] [<c1042010>] ?
run_timer_softirq+0x150/0x1f3
May 26 03:19:01 debian kernel: [10947.008656] [<c1231393>] ?
netif_tx_unlock+0x3a/0x3a
May 26 03:19:01 debian kernel: [10947.008672] [<c103ce5d>] ?
local_bh_enable+0x2/0x2
May 26 03:19:01 debian kernel: [10947.008687] [<c103cef1>] ?
__do_softirq+0x94/0x12f
May 26 03:19:01 debian kernel: [10947.008702] [<c103ce5d>] ?
local_bh_enable+0x2/0x2
May 26 03:19:01 debian kernel: [10947.008710] <IRQ> [<c103d0e2>] ?
irq_exit+0x32/0x80
May 26 03:19:01 debian kernel: [10947.008762] [<c100cd7a>] ? do_IRQ+0x65/0x76
May 26 03:19:01 debian kernel: [10947.008787] [<c12c5bf0>] ?
common_interrupt+0x30/0x38
May 26 03:19:01 debian kernel: [10947.008825] [<c10f1dc1>] ?
__fsnotify_parent+0x80/0x87
May 26 03:19:01 debian kernel: [10947.008844] [<c10cb955>] ?
wait_on_retry_sync_kiocb+0x3c/0x3c
May 26 03:19:01 debian kernel: [10947.008858] [<c10cb955>] ?
wait_on_retry_sync_kiocb+0x3c/0x3c
May 26 03:19:01 debian kernel: [10947.008872] [<c10cb901>] ?
fsnotify_modify+0x37/0x4f
May 26 03:19:01 debian kernel: [10947.008887] [<c10cc1c8>] ?
vfs_write+0xa4/0xd4
May 26 03:19:01 debian kernel: [10947.008901] [<c10cc367>] ?
sys_write+0x3d/0x61
May 26 03:19:01 debian kernel: [10947.008916] [<c12c565f>] ?
sysenter_do_call+0x12/0x28
May 26 03:19:01 debian kernel: [10947.008927] ---[ end trace
d751668d50ee9171 ]---
May 26 03:19:01 debian kernel: [10947.008943] eth2: Transmit timed
out, TxStatus 00 TxFrameId bc, resetting...
The /var/log/syslog gets piled with messages like these:
May 26 16:37:35 debian kernel: [58861.160666] ath: Could not stop RX,
we could be confusing the DMA engine when we start RX up
May 26 16:37:36 debian kernel: [58861.514885] ath: DMA failed to stop
in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00008040
May 26 16:37:36 debian kernel: [58861.514987] ath: Could not stop RX,
we could be confusing the DMA engine when we start RX up
May 26 16:37:36 debian kernel: [58861.869302] ath: DMA failed to stop
in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00008040
May 26 16:37:36 debian kernel: [58861.869398] ath: Could not stop RX,
we could be confusing the DMA engine when we start RX up
May 26 16:37:37 debian kernel: [58862.223665] ath: DMA failed to stop
in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00008040
May 26 16:37:37 debian kernel: [58862.223769] ath: Could not stop RX,
we could be confusing the DMA engine when we start RX up
May 26 16:37:37 debian kernel: [58862.578063] ath: DMA failed to stop
in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006040
May 26 16:37:37 debian kernel: [58862.578163] ath: Could not stop RX,
we could be confusing the DMA engine when we start RX up
I'm confusing what causes this problem. I tend to blame a bug in ath9k module.
--
With Best Regards,
Gary Trotcko
Reply to: