Modify

Opened 7 years ago

Closed 7 years ago

Last modified 7 years ago

#8446 closed defect (duplicate)

ath9k 11n fast dies with mac80211 2010-12-09

Reported by: anonymous Owned by: nbd
Priority: normal Milestone: Backfire 10.03.1
Component: kernel Version: Trunk
Keywords: Cc:

Description

Linksys WRT160NL with backfire updated today to r24505. Notebook with intel 5100 card and WinXP driver 13.4.0.9.

New version of ath9k driver dies fast when transfer big files (8GB) over 11n link. Speed starts from 7MB/s but after transfer ~4GB of data decrease to 30kB/s and icmp echo looks like:

11 packets transmitted, 6 received, 45% packet loss, time 10032ms
rtt min/avg/max/mdev = 205.271/2036.771/4397.252/1526.104 ms, pipe 5

With older backfire mac80211 2010-10-19 such transfer of 8GB files works without problem with full speed (7MB/s).

Attachments (0)

Change History (98)

comment:1 Changed 7 years ago by kra4ol4e <kra4ol4e@…>

Im not sure if its related, but I get the following messages in kernel log with r24504 (WRT160NL):

ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!

comment:2 Changed 7 years ago by nbd

  • Owner changed from developers to nbd
  • Status changed from new to accepted

comment:3 Changed 7 years ago by nbd

the stability issues should be fixed in r24678, please test.

comment:4 Changed 7 years ago by anonymous

Tested with backfire r24714 - problem not fixed.

Transfer 12GB file over ftp, 11n, WinXP, intel 5100. Transfered without problems 9GB with full speed of 7MB/s, then decrease to 30kB/s. And the same situation with icmp echo. Log output:

Dec 19 09:09:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: group key handshake completed (RSN)
Dec 19 09:09:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: group key handshake completed (RSN)
Dec 19 09:19:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: group key handshake completed (RSN)
Dec 19 09:19:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: deauthenticated due to local deauth request
Dec 19 09:19:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: authenticated
Dec 19 09:19:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: associated (aid 1)
Dec 19 09:19:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: pairwise key handshake completed (RSN)
Dec 19 09:29:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: group key handshake completed (RSN)
Dec 19 09:29:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: deauthenticated due to local deauth request
Dec 19 09:29:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: authenticated
Dec 19 09:29:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: associated (aid 1)
Dec 19 09:29:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: pairwise key handshake completed (RSN)
Dec 19 09:31:38 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Dec 19 09:31:38 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Dec 19 09:31:38 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Dec 19 09:31:38 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Dec 19 09:32:06 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Dec 19 09:32:06 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Dec 19 09:32:06 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Dec 19 09:38:01 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Dec 19 09:38:01 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Dec 19 09:38:01 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Dec 19 09:39:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: group key handshake completed (RSN)
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: deauthenticated due to local deauth request
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: authenticated
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: associated (aid 1)
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: associated (aid 1)
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
Dec 19 09:39:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: pairwise key handshake completed (RSN)
Dec 19 09:49:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: group key handshake completed (RSN)
Dec 19 09:49:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: received EAPOL-Key 2/2 Group with unexpected replay counter
Dec 19 09:49:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: deauthenticated due to local deauth request
Dec 19 09:49:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: authenticated
Dec 19 09:49:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: associated (aid 1)
Dec 19 09:49:55 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
Dec 19 09:49:58 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: deauthenticated due to local deauth request
Dec 19 09:49:59 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: authenticated
Dec 19 09:49:59 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 IEEE 802.11: associated (aid 1)
Dec 19 09:49:59 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: pairwise key handshake completed (RSN)
Dec 19 09:59:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:7b WPA: group key handshake completed (RSN)
Dec 19 09:59:52 OpenWrt daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:a4 WPA: group key handshake completed (RSN)

7b - intel 3945 with 2.6.32.27 kernel driver, no traffic when doing test.

a4 - intel 5100, winxp.

comment:5 Changed 7 years ago by nbd

Could you please test the mac80211 version from r24262 (along with the rest of backfire from the latest rev)
I want to make sure that this bug was not there already in the latest version based on 2010-10-19.

comment:6 Changed 7 years ago by igor

Previous messages from anonymous was by me.

Builded backfire r24714 with mac80211 r24262. Transfer already 24GB over 11n. No drops of speed to 30kB/s and no problems with icmp echo. Also no messages in log about TX DMA.

I worked with mac80211 r24262 for 1 week prior r24505 and hasn't any problems with TX DMA in logs.

comment:7 Changed 7 years ago by nbd

Thanks, I'll focus on reviewing the differences between those two versions then.

The Tx DMA stop messages are probably not an indicator of this issue, because these messages were hidden in older versions. They would only be shown with KERN_DEBUG priority, and only if the 'Atheros wireless driver debugging' config option in menuconfig was activated. I believe the DMA stop issues have been there for a long time, probably even from the beginning of ath9k.

comment:8 Changed 7 years ago by nbd

Please try this patch: http://nbd.name/ath9k-fixes.patch

comment:9 Changed 7 years ago by Aaron

Applied patch to trunk, reflashed, and yet to see the errors posted above. This is under light use so far though using R52N mini pci. I did have several mentions in my logs prior to the reflash, just have to watch it and see what happens.

comment:10 Changed 7 years ago by igor

No, problem isn't fixed with this patch.

comment:12 Changed 7 years ago by igor

Second patch didn't help as well.

comment:13 Changed 7 years ago by nbd

When the issue occurs, could you please test RX and TX throughput individually? I'd like to know which one is worse.

comment:14 Changed 7 years ago by Aaron

I guess the part I'm missing to conduct this test is the intel card. I have a wide assortment of usb/mini pci but all realtek/ralink/atheros and I can't seem to make the errors happen. It does seem that when I deploy access points into the wild I tend to have more issues and have noticed MAC laptops having problems. Maybe they are intel based?

comment:15 Changed 7 years ago by nbd

Aaron: this issue might also be specific to AR913x

comment:16 Changed 7 years ago by igor

wrt160nl, backfire r24820.

I got another laptop with intel 5100. It has win7 x32 with the same version of intel driver. For now I got this issues with it:
1) average transfer speed = 4.2MB/s (tx bitrate: 65.0 MBit/s MCS 7)
2) ath9k warning:

ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
------------[ cut here ]------------
WARNING: at /home/igor/data/src/temp/linksys_backfire_r24821/backfire/build_dir/linux-ar71xx/compat-wireless-2010-12-16/drivers/net/wireless/ath/ath9k/xmit.c:295 0x80c48e18()
Modules linked in: xt_IMQ nf_nat_tftp nf_conntrack_tftp nf_nat_irc nf_conntrack_irc nf_nat_ftp nf_conntrack_ftp xt_HL xt_hl xt_MARK ipt_ECN xt_CLASSIFY xt_time xt_tcpmss xt_statistic xt_mark xt_length ipt_ecn xt_DSCP xt_dscp xt_string xt_layer7 ipt_MASQUERADE iptable_nat nf_nat xt_CONNMARK xt_recent xt_helper xt_conntrack xt_connmark xt_connbytes xt_NOTRACK iptable_raw xt_state nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack pppoe pppox ipt_REJECT xt_TCPMSS ipt_LOG xt_comment xt_multiport xt_mac xt_limit iptable_mangle iptable_filter ip_tables xt_tcpudp x_tables ppp_async ppp_generic slhc ath9k ath9k_common ath9k_hw ath mac80211 ts_fsm ts_bm ts_kmp sch_red sch_sfq sch_hfsc crc_ccitt cls_fw imq cfg80211 compat_firmware_class compat arc4 aes_generic deflate ecb cbc leds_gpio button_hotplug gpio_buttons input_polldev input_core
Call Trace:[<8007e010>] 0x8007e010
[<80068374>] 0x80068374
[<80068374>] 0x80068374
[<8007cf1c>] 0x8007cf1c
[<80c48e18>] 0x80c48e18
[<80c48e18>] 0x80c48e18
[<801de270>] 0x801de270
[<80c4a3e8>] 0x80c4a3e8
[<800a0000>] 0x800a0000
[<80c44bb8>] 0x80c44bb8
[<80082170>] 0x80082170
[<800a80bc>] 0x800a80bc
[<80082964>] 0x80082964
[<80082a44>] 0x80082a44
[<8006082c>] 0x8006082c
[<80060a00>] 0x80060a00
[<8024881c>] 0x8024881c
[<8006c75c>] 0x8006c75c
[<80060a20>] 0x80060a20
[<802bfa54>] 0x802bfa54
[<802bf3a8>] 0x802bf3a8

---[ end trace 30edfe576f6be65b ]---
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame

Aaron: yes, I personally dislike Intel's drivers for Windows. I always have some troubles with ath9k on AR913x and them: periodical slow transfer speed for 11n (only 3MB/s), frequent reconnects as you seen above (deauthenticated due to local deauth request - authenticated - associated - deauthenticated due to local deauth request - ...). Linux driver don't show such troubles, but it has some bugs for 11n in binary firmware (https://bugs.launchpad.net/ubuntu/maverick/+source/linux-firmware/+bug/630748). And I don't know if this firmware is identical for Linux/Windows drivers or not. But for me this situation isn't obviosly Intel's based, so I opened this ticket.

comment:17 Changed 7 years ago by nbd

igor: please ignore the 'Failed to stop TX DMA' messages for now. I'm pretty sure they were happening with the eariler versions as well, though hidden by default, so this is not a new issue.

You mentioned that you occasionally only get 30 kb/s throughput with high latencies. I'd like to know if rx is faster than tx in that case, or if it's the other way around.

comment:18 Changed 7 years ago by igor

nbd: easily reproduce problem with first laptop. No differences about tx/rx here. In both direction average speed 20-30kB/s, high peak ~50-150kB/s, low peak ~2-5kB/s. Latency:

399 packets transmitted, 385 received, 3% packet loss, time 400054ms
rtt min/avg/max/mdev = 1.952/5481.027/10126.046/2746.302 ms, pipe 11

And after some time (5-10min) probing both directions laptop stops answer over tcp/ip. ip neigh on router show INCOMPLETE or FAILED state. iw station dump:

Station 00:21:5d:97:e9:a4 (on wlan0)
	inactive time:	19490 ms
	rx bytes:	9746814
	rx packets:	72069
	tx bytes:	190089035
	tx packets:	130137
	signal:  	-38 dBm
	tx bitrate:	65.0 MBit/s MCS 

Station 00:21:5d:97:e9:a4 (on wlan0)
	inactive time:	21530 ms
	rx bytes:	9746814
	rx packets:	72069
	tx bytes:	190089035
	tx packets:	130137
	signal:  	-38 dBm
	tx bitrate:	65.0 MBit/s MCS 7

Station 00:21:5d:97:e9:a4 (on wlan0)
	inactive time:	30 ms
	rx bytes:	9748198
	rx packets:	72110
	tx bytes:	190090190
	tx packets:	130144
	signal:  	-41 dBm
	tx bitrate:	65.0 MBit/s MCS 7

Station 00:21:5d:97:e9:a4 (on wlan0)
	inactive time:	40 ms
	rx bytes:	9748510
	rx packets:	72122
	tx bytes:	190090190
	tx packets:	130144
	signal:  	-40 dBm
	tx bitrate:	65.0 MBit/s MCS 7

Station 00:21:5d:97:e9:a4 (on wlan0)
	inactive time:	0 ms
	rx bytes:	9748744
	rx packets:	72131
	tx bytes:	190090190
	tx packets:	130144
	signal:  	-40 dBm
	tx bitrate:	65.0 MBit/s MCS 7

And then happens reconnect process (deauthenticated due to local deauth request - authenticated - associated) and laptop works again.

comment:19 follow-up: Changed 7 years ago by igor

Bought WNDR3700 for home. Can not reproduce problem with its 2.4GHz radio with backfire mac80211 r24820.

comment:20 Changed 7 years ago by anonymous

Not sure if this relates to this problem, so I just put it on pastebin for now. The latest mac80211/ath9k was being used from trunk.

http://pastebin.com/J2RWkPJ6

comment:21 in reply to: ↑ 19 Changed 7 years ago by anonymous

And you're still stable?

At first it sounded a little bit like at #7697.
But in your case the wndr3700 seems to help.. .

But its worlds more stable anyways at the moment, so I can reproduce it on an very irregular basis only with current trunk builds. (And if so, a client reboot is enough, which it was not some time ago.)

Unfortunately there are no uCode updates for our older Intel cards.

Replying to igor:

Bought WNDR3700 for home. Can not reproduce problem with its 2.4GHz radio with backfire mac80211 r24820.

comment:22 follow-up: Changed 7 years ago by igor

Yes, with WNDR3700 problem is gone now. Tested again WRT160NL on Jan 05 2011 with latest trunk and got problem back.

comment:23 in reply to: ↑ 22 Changed 7 years ago by anonymous

Does the problem resolve after a reconnect, a router reboot or a client reboot?

Replying to igor:

Yes, with WNDR3700 problem is gone now. Tested again WRT160NL on Jan 05 2011 with latest trunk and got problem back.

comment:24 Changed 7 years ago by igor

Reconnect is a temporary solution for this problem. No need of reboot one or the other.

comment:25 follow-up: Changed 7 years ago by nbd

@igor: I now have an embedded board with Windows XP and an Intel 6300 card. Earlier today, I was able to reproduce issues similar to what you were describing. Now with a mac80211 upgrade and some fixes that I made in r24949, those issues seem to be gone in my tests.

I have iperf running between a laptop behind the AP and the WinXP STA and aside from occasional short throughput drops (1-2 seconds), it seems stable. Please try this on your device.

comment:26 Changed 7 years ago by igor

@nbd: tested WRT160NL with mac80211 from trunk r24954. No problem after transfer of 50GB. Thanks.

comment:27 Changed 7 years ago by nbd

  • Resolution set to fixed
  • Status changed from accepted to closed

comment:28 in reply to: ↑ 25 Changed 7 years ago by anonymous

Still having a problem with the Intel:

64 bytes from 192.168.0.110: seq=0 ttl=128 time=2.877 ms
64 bytes from 192.168.0.110: seq=1 ttl=128 time=4534.750 ms
64 bytes from 192.168.0.110: seq=3 ttl=128 time=2546.539 ms
64 bytes from 192.168.0.110: seq=13 ttl=128 time=199.299 ms
64 bytes from 192.168.0.110: seq=14 ttl=128 time=18.359 ms
64 bytes from 192.168.0.110: seq=15 ttl=128 time=42.199 ms
64 bytes from 192.168.0.110: seq=16 ttl=128 time=66.380 ms
64 bytes from 192.168.0.110: seq=17 ttl=128 time=90.014 ms
64 bytes from 192.168.0.110: seq=18 ttl=128 time=114.201 ms
64 bytes from 192.168.0.110: seq=19 ttl=128 time=137.936 ms
64 bytes from 192.168.0.110: seq=20 ttl=128 time=161.514 ms
64 bytes from 192.168.0.110: seq=21 ttl=128 time=7137.576 ms
64 bytes from 192.168.0.110: seq=22 ttl=128 time=6143.439 ms
64 bytes from 192.168.0.110: seq=29 ttl=128 time=4986.035 ms
64 bytes from 192.168.0.110: seq=30 ttl=128 time=3988.766 ms
64 bytes from 192.168.0.110: seq=31 ttl=128 time=2989.274 ms
64 bytes from 192.168.0.110: seq=32 ttl=128 time=1991.587 ms
64 bytes from 192.168.0.110: seq=33 ttl=128 time=991.942 ms
64 bytes from 192.168.0.110: seq=34 ttl=128 time=1.016 ms
64 bytes from 192.168.0.110: seq=35 ttl=128 time=1.060 ms
64 bytes from 192.168.0.110: seq=36 ttl=128 time=1.079 ms
64 bytes from 192.168.0.110: seq=37 ttl=128 time=2.480 ms
64 bytes from 192.168.0.110: seq=38 ttl=128 time=1.088 ms
64 bytes from 192.168.0.110: seq=39 ttl=128 time=1.103 ms
64 bytes from 192.168.0.110: seq=40 ttl=128 time=1.092 ms
64 bytes from 192.168.0.110: seq=41 ttl=128 time=48.175 ms
64 bytes from 192.168.0.110: seq=42 ttl=128 time=72.644 ms
64 bytes from 192.168.0.110: seq=43 ttl=128 time=95.404 ms
64 bytes from 192.168.0.110: seq=50 ttl=128 time=2.159 ms
64 bytes from 192.168.0.110: seq=51 ttl=128 time=1.415 ms
64 bytes from 192.168.0.110: seq=52 ttl=128 time=2.304 ms

After some traffic in both directions.
And same "deauthenticated due to local deauth request - authenticated - associated" message.

Replying to nbd:

@igor: I now have an embedded board with Windows XP and an Intel 6300 card. Earlier today, I was able to reproduce issues similar to what you were describing. Now with a mac80211 upgrade and some fixes that I made in r24949, those issues seem to be gone in my tests.

I have iperf running between a laptop behind the AP and the WinXP STA and aside from occasional short throughput drops (1-2 seconds), it seems stable. Please try this on your device.

comment:29 Changed 7 years ago by anonymous

i have the same problem
trunk svn r25094


Jan 26 19:14:36 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:14:36 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:14:36 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:14:36 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:16:10 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:16:10 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:16:10 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:16:10 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Jan 26 19:16:10 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Jan 26 19:16:10 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Jan 26 19:16:20 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:16:20 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:16:20 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:16:20 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Jan 26 19:16:20 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Jan 26 19:16:20 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Jan 26 19:17:00 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:17:00 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:17:00 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:17:12 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:17:12 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:17:12 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:18:25 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:18:25 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:18:25 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:18:28 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:18:28 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:18:28 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:18:44 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:18:44 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:18:44 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:19:22 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:19:22 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:19:22 OpenWrt user.err kernel: ath: Failed to stop TX DMA!
Jan 26 19:19:26 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:19:26 OpenWrt user.err kernel: ath: Failed to stop TX DMA in 100 msec after killing last frame
Jan 26 19:19:26 OpenWrt user.err kernel: ath: Failed to stop TX DMA!

comment:30 follow-up: Changed 7 years ago by nbd

Please clarify what you mean by 'same problem' - do you just see those messages or do you see wifi hangs as well. Also please provide some details on the configuration, simply pasting the messages with no context is useless to me.

comment:31 in reply to: ↑ 30 Changed 7 years ago by anonymous

I meant the wifi hangs (very high response time) like in the log above.
Laptop with Intel 4965 card on Vista (XP works better!) on WNDR3700 with 2,4GHz N.

Often instantly after standby or hibernate. If not, transfers in both directions will lead to it.

Just describe what debugging parameters or additional info you want! I can reproduce it so good, I would log anything for you!

Don't know if the 6300 will do it, but I think so.

I always was able to reproduce it with two short scripts which are looping, one for a file transfer to another actual windows 7 client, and one which receives from the same one, which is connected directly over lan to the wndr. So just reading from and writing to normal Windows "cifs" shares.. .

After some time the default ping timeout from Windows leads to the situation that 3 pings over wifi are going through to the router, then at least one is missing. And then 3 are working again, after that at least one is missing - and so on. From the router itself to the client, the log can be seen above.
It's so bad because you can't really remote control anything with a mouse, nor do you get happy with a so hard lagging connection to a terminal.. .

Replying to nbd:

Please clarify what you mean by 'same problem' - do you just see those messages or do you see wifi hangs as well. Also please provide some details on the configuration, simply pasting the messages with no context is useless to me.

comment:32 Changed 7 years ago by anonymous

ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA in 100 msec after killing last frame
ath: Failed to stop TX DMA!

comment:33 Changed 7 years ago by anonymous

  • Resolution fixed deleted
  • Status changed from closed to reopened

Openwrt: Backfire (10.03, r26231)
Device: Tp-Link TL-WR1043ND v1.8

# dmesg
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020

# cat /etc/config/wireless
config 'wifi-device' 'radio0'
        option 'type' 'mac80211'
        option 'macaddr' '74:ea:xx:xx:xx:xx'
        option 'disabled' '0'
        option 'channel' '1'
        option 'hwmode' '11g'
        option 'country' 'PL'

config 'wifi-iface'
        option 'device' 'radio0'
        option 'network' 'lan'
        option 'mode' 'ap'
        option 'ssid' 'xxxxx'
        option 'encryption' 'psk2'
        option 'key' 'xxxxxxxxxxxxx'

comment:34 Changed 7 years ago by jeyjay

I can confirm this. It takes only a few hours until connection fails. No reconnect with any device possible.

Device: Asus WL-500gP with Atheros miniPCI (ath9k)

comment:35 follow-up: Changed 7 years ago by nbd

  • Resolution set to fixed
  • Status changed from reopened to closed

Should be fixed with r26252

comment:36 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

  • Resolution fixed deleted
  • Status changed from closed to reopened

Built 26252

ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
device wlan0 entered promiscuous mode
br-lan: port 2(wlan0) entering forwarding state
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020

comment:37 Changed 7 years ago by nbd

  • Resolution set to worksforme
  • Status changed from reopened to closed

The message is a known issue and is not necessarily an indicator of a connection hang. Please only reopen the ticket if you have something that is relevant to this issue.

comment:38 in reply to: ↑ 35 Changed 7 years ago by anonymous

Replying to nbd:

Should be fixed with r26252

Will the automatic build system generate new trunk images soon?
The last images were generated on March 20. The fix was made available on march 21.
We are march 22, and still no corrective images!!!
http://downloads.openwrt.org/snapshots/trunk/ar71xx/

Thanks!

comment:39 Changed 7 years ago by jeyjay

  • Resolution worksforme deleted
  • Status changed from closed to reopened

Still trouble to reconnect. This happens to my Palm Pixi after 1 day uptime of my router (Asus WL-500gP, r26255):

Mar 22 23:25:14 Internetgemeinschaft daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Mar 22 23:26:25 Internetgemeinschaft daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: authenticated
Mar 22 23:27:46 Internetgemeinschaft daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Mar 22 23:28:00 Internetgemeinschaft daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: authenticated
Mar 22 23:28:03 Internetgemeinschaft daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Mar 22 23:29:26 Internetgemeinschaft daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Mar 22 23:29:49 Internetgemeinschaft daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: authenticated
Mar 22 23:29:51 Internetgemeinschaft daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: authenticated
Mar 22 23:30:23 Internetgemeinschaft daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: authenticated
Mar 22 23:30:23 Internetgemeinschaft daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: authenticated
Mar 22 23:34:04 Internetgemeinschaft daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response

My Laptop (Broadcom Wifi) has the same problems but don't even appear in the system log.

comment:40 Changed 7 years ago by jeyjay

ok, things are a bit more complicated. After several reconnection attempts it is possible to connect to the router. My mobile phone does this automatically when it sees a known wifi network. So after some time it is able to connect to the wifi network. In case of my laptop I got the message "Windows was unable to connect to ...". So I gave up. This morning I saw that my mobile was connected so gave another try. And it worked.
It turns out that 1 out of 3 tries are successful.

comment:41 Changed 7 years ago by jeyjay

dying wireless still lasting with r26301. No reconnect possible after some hours of uptime.

comment:42 follow-up: Changed 7 years ago by nbd

Please try r26506, it also fixes the "failed to stop RX DMA" messages

comment:43 in reply to: ↑ 42 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

Replying to nbd:

Please try r26506, it also fixes the "failed to stop RX DMA" messages

The problem seems to be fixed. Good gob. Thanks.

I tested on tl-1043 with Intel 4965AGN

comment:44 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

Oopps! Today I got it again in the log

Apr  8 11:39:05 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 11:39:05 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 11:39:05 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020

comment:45 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

But the change is that it is not 20-30 times but only twice. I will test more.

comment:46 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

Oops! Again.

Apr  8 12:30:25 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:25 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:25 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:25 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:25 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:25 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:26 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:26 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:26 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:27 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:27 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:27 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:28 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:28 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:28 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:30 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:30 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:30 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:31 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:31 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:31 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:32 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:32 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:32 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:32 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:32 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:32 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:33 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:33 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:33 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:34 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:34 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:34 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:35 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:35 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:35 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:35 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:35 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:35 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:38 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:38 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:38 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:39 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:39 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:39 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:39 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:39 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:39 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:39 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:39 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:39 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:40 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:40 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:41 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:41 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:41 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:41 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:41 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:41 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:42 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:42 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:42 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:43 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:43 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:43 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:44 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:44 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:44 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:44 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:44 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:44 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:44 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:44 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:44 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:46 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:46 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:46 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:46 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:46 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:46 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:47 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:47 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:47 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:48 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:48 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:48 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:48 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:48 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:48 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:48 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:48 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:48 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:50 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 12:30:50 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 12:30:50 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 13:06:52 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: group key handshake completed (RSN)
Apr  8 13:06:58 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 13:06:58 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 13:06:58 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 13:08:01 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
Apr  8 13:08:01 OpenWrt user.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Apr  8 13:08:01 OpenWrt user.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020

comment:47 Changed 7 years ago by nbd

Please update to the latest version and if the issue occurs again, post some new logs. I added some extra debugging information to help track this down.

comment:48 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

I can't test trunk for a long time, because openl2tp does not start there. I built from trunk and no errors for a few hours. Then installed backfire back.

comment:49 Changed 7 years ago by nbd

Is there a ticket with details about your openl2tp issue yet?

comment:50 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

Yes 9204 about openl2tp. It works in backfire, but does not from trunk.

'ath: DMA failed to stop' issue seems to be fixed. At least 24 hours no errors.

comment:51 Changed 7 years ago by nbd

jeyjay: any more reconnect issues left in the current version?

comment:52 Changed 7 years ago by anonymous

This problem still exists in r26614, though is less prevalent than in versions pre-25988. Those older versions needed to be reset every few days because of this issue. I don't have a feel for the reliability of the latest versions, but I know I can produce the problem by running /sbin/wifi. Though that may be a tad unfair, a real deployment will also encounter this bug eventually.

Setup: 1 pair Ubiquity SR71-15 (AR9220) on Ubiquity Routerstation (AR7161 rev. 2) operating in infrastructure mode with WDS bridging.

root@openwrtr26614:/# wifi
br-lan: port 2(wlan0) entering forwarding state
cfg80211: Calling CRDA to update world regulatory domain
br-lan: port 2(wlan0) entering disabled state
cfg80211: World regulatory domain updated:
cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
device wlan0 left promiscuous mode
br-lan: port 2(wlan0) entering disabled state
device wlan0 entered promiscuous mode
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028040
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up


WARNING: at /home/computer/openwrt_aa/build_dir/linux-ar71xx_generic/compat-wireless-2011-04-06/drivers/net/wireless/ath/ath9k/recv.c:504 0x83be6d68()
Modules linked in: ohci_hcd nf_nat_irc nf_conntrack_irc nf_nat_ftp nf_conntrack_ftp ipt_MASQUERADE iptable_nat nf_nat xt_NOTRACK iptable_raw xt_state nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack ehci_hcd pppoe pppox ipt_REJECT xt_TCPMSS ipt_LOG xt_comment xt_multiport xt_mac xt_limit iptable_mangle iptable_filter ip_tables xt_tcpudp x_tables ppp_async ppp_generic slhc ath9k ath9k_common ath9k_hw ath mac80211 usbcore nls_base crc_ccitt cfg80211 compat arc4 aes_generic crypto_algapi leds_gpio button_hotplug gpio_keys_polled input_polldev input_core
Call Trace:[<80075de8>] 0x80075de8
[<8023e470>] 0x8023e470
[<8023e470>] 0x8023e470
[<80074b00>] 0x80074b00
[<83be6d68>] 0x83be6d68
[<83bf0000>] 0x83bf0000
[<80074b44>] 0x80074b44
[<80180278>] 0x80180278
[<83be6d68>] 0x83be6d68
[<80180278>] 0x80180278
[<83be42cc>] 0x83be42cc
[<83be4ed8>] 0x83be4ed8
[<83be2a0c>] 0x83be2a0c
[<83be5254>] 0x83be5254
[<83be58d0>] 0x83be58d0
[<83b45390>] 0x83b45390
[<83b456a8>] 0x83b456a8
[<83b45390>] 0x83b45390
[<800862e8>] 0x800862e8
[<8008840c>] 0x8008840c
[<8023ecfc>] 0x8023ecfc
[<800881d0>] 0x800881d0
[<800881d0>] 0x800881d0
[<8008bc3c>] 0x8008bc3c
[<80063ca0>] 0x80063ca0
[<8008bbbc>] 0x8008bbbc
[<80063c90>] 0x80063c90

---[ end trace d6621b67ad486154 ]---
root@openwrtr26614:/# ath: Failed to stop TX DMA!
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028040
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: Failed to stop TX DMA!
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028040
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: Failed to stop TX DMA!
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028040
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: Failed to stop TX DMA!
...

I've seen DMADBG_7 to be any one of: 0x28040, 0x26040, 0x8040, and 0x6040. The value changes often once the bug is triggered and the initial value is not always 0x28040.

Removing all modules from the compat-wireless package and reinserting them does not fix this. I have also tried not setting the AR_DIAG_RX_ABORT bit in ath9k_hw_abortpcurecv thinking it may cause a problem and that didn't help. I'm running out of ideas. Do you have any ideas or advice?

comment:53 follow-up: Changed 7 years ago by nbd

Are you absolutely sure that these kernel messages are connected to the issue of not being able to connect to the AP anymore? If so, how can you tell?

comment:54 in reply to: ↑ 53 Changed 7 years ago by anonymous

Replying to nbd:

Are you absolutely sure that these kernel messages are connected to the issue of not being able to connect to the AP anymore? If so, how can you tell?

Definitely.

Short answer: antenna cables, power converter, and oscilloscope show the radio goes completely silent when this bug triggers.

Long answer: the block of messages at the bottom of this post reprint indefinitely at a very rapid rate. AR_CR=0x24 all the time, the third bit being RX enable. My guess is TX does not work when RX cannot be stopped as the radio is half-duplex and requires a SIFS. Now getting into semantics, in previous versions the bug would occur immediately after successful association and authentication, so the STA does connect to the AP before it goes silent, causing the AP to drop association. (Hostapd-full on AP, wpa-supplicant-full on STA.) The bug would occur whether encryption was set or not.

I have not traced what is happening in the newest version, but I can say that when this would happen in older versions, ath9k/main.c: ath_set_channel would call ath_stoprecv and that would cause the DMA errors to print and another ath9k_hw_reset. I'll post any new insights into what is going wrong in the current version as I find them.

ath: Failed to stop TX DMA!
ath: DMA failed to stop in 10 ms
AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028040
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up

comment:55 Changed 7 years ago by nbd

OK, that makes sense. I still think there's a chance that the message has nothing to do with the underlying issue, but is simply a symptom that occurs during a hardware reset under some circumstances.

The reason why it also happens when the AP gets stuck is probably because whatever is (or was) causing the issue triggers stuck beacons and/or baseband hangs, which trigger the driver to issue hardware reset, which in turn generates these messages.

If this happens when the AP is getting stuck, I'm specifically interested in the DMADBG_7 value at that point in time.

comment:56 Changed 7 years ago by anonymous

In AP mode as in STA mode, the value at DMADBG_7 will change to any one of {0x6040, 0x8040, 0x26040, 0x28040} when left in this broken state. In case the first reported value has any extra weight, I have triggered the error on the AP 5 times and recorded the first value. Those are:
1) 0x6040
2) 0x28040
3) 0x28040
4) 0x6040
5) 0x28040

If this were caused by a stuck beacon-induced hardware reset, the driver must first start missing beacons, so I enabled the ATH_DBG_BSTUCK flag in ath9k/debug. The driver first reports missed beacons after the stop-DMA errors, not before. (Log segment below.) If the baseband hangs, might there be an earlier place to print out DMADBG_7 than in ath9k_hw_stopdmarecv?

I should have mentioned that the way I am producing this error is by running wifi a few times a minute on one of the Routerstations while sending and receiving iperf-generated UDP streams through the WAN/WLAN bridge. This produces the same symptoms as I have seen on an outdoor link carrying internet traffic, only running "wifi" can make it happen in minutes instead of days. The way I see it, if running "wifi" can cause the radio hardware to enter a bad state, so can signal fading. Diagram:
PC <--ethernet--> Routerstation <--wireless--> Routerstation <--ethernet--> PC

Thanks for continuing to look into this.

Jan 1 00:03:00 openwrtr26614 kern.info kernel: device wlan0 entered promiscuous mode
Jan 1 00:03:00 openwrtr26614 kern.info kernel: br-lan: port 2(wlan0) entering forwarding state
Jan 1 00:03:00 openwrtr26614 kern.info kernel: br-lan: port 2(wlan0) entering forwarding state
Jan 1 00:03:10 openwrtr26614 kern.info kernel: device wlan0 left promiscuous mode
Jan 1 00:03:10 openwrtr26614 kern.info kernel: br-lan: port 2(wlan0) entering forwarding state
Jan 1 00:03:10 openwrtr26614 kern.info kernel: br-lan: port 3(wlan0.sta1) entering forwarding state
Jan 1 00:03:10 openwrtr26614 kern.info kernel: device wlan0.sta1 left promiscuous mode
Jan 1 00:03:10 openwrtr26614 kern.info kernel: br-lan: port 3(wlan0.sta1) entering disabled state
Jan 1 00:03:11 openwrtr26614 kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006040
Jan 1 00:03:11 openwrtr26614 kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: ------------[ cut here ]------------
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: WARNING: at /home/computer/openwrt_aa/build_dir/linux-ar71xx_generic/compat-wireless-2011-04-06/drivers/net/wireless/ath/ath9k/recv.c:504 0x83be6d68()
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: Modules linked in: ohci_hcd nf_nat_irc nf_conntrack_irc nf_nat_ftp nf_conntrack_ftp ipt_MASQUERADE iptable_nat nf_nat xt_NOTRACK iptable_raw xt_state nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack ehci_hcd pppoe pppox ipt_REJECT
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: Call Trace:[<80075de8>] 0x80075de8
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<8023e470>] 0x8023e470
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<8023e470>] 0x8023e470
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<80074b00>] 0x80074b00
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<83be6d68>] 0x83be6d68
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<83bf0000>] 0x83bf0000
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<801c7d20>] 0x801c7d20
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<801b3830>] 0x801b3830
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<800df0ac>] 0x800df0ac
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<800e1e1c>] 0x800e1e1c
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<801b428c>] 0x801b428c
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<800d2238>] 0x800d2238
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<800df14c>] 0x800df14c
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<800cf058>] 0x800cf058
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: [<800691a4>] 0x800691a4
Jan 1 00:03:11 openwrtr26614 kern.warn kernel: ---[ end trace 4a5a9865394c57a5 ]---
Jan 1 00:03:11 openwrtr26614 kern.info kernel: device wlan0 entered promiscuous mode
Jan 1 00:03:11 openwrtr26614 kern.info kernel: br-lan: port 2(wlan0) entering forwarding state
Jan 1 00:03:11 openwrtr26614 kern.info kernel: br-lan: port 2(wlan0) entering forwarding state
Jan 1 00:03:11 openwrtr26614 kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006040
Jan 1 00:03:11 openwrtr26614 kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 1 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 2 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 3 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 4 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 5 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 6 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 7 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: missed 8 consecutive beacons
Jan 1 00:03:12 openwrtr26614 kern.debug kernel: ath: beacon is officially stuck
Jan 1 00:03:12 openwrtr26614 kern.err kernel: ath: Failed to stop TX DMA!
Jan 1 00:03:12 openwrtr26614 kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006040
Jan 1 00:03:12 openwrtr26614 kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up

comment:57 Changed 7 years ago by vaden@…

Please be so kind as to share your debug settings so that we may explore a somewhat similar issue on a small rural point of presence (a 2.4 GHz operation, unrelated to the M900 save the manufacturer and chipset are common).

THANKS/regards/ldv

ar71xx-wdt: enabling watchdog timer
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020
root@jv-2400-ap1:~# cat /etc/banner
  _______                     ________        __
 ATTITUDE ADJUSTMENT (bleeding edge, r26358) ----------

comment:58 Changed 7 years ago by nbd

Larry: your version is too old, it does not contain the changes that fix the main source of DMA rx issues, or several other stability fixes.

comment:59 Changed 7 years ago by vaden@…

OK, that rock has been turned over, what's the next rock to turn over?

I am so used to semiannual release cycles, I am having trouble modulating at the correct f ...

One rural 2.4 GHz pop plausibly operating Euro-style at 20 dBm + MTI 7.5 dBi omni, ready to rock and roll with the best OS and thus the best developers in the WORLD!

While /etc/banner says r26648, the file fed to sysupgrade was openwrt-r26651-rocket-m-squashfs-sysupgrade.bin.

BusyBox v1.18.4 (2011-04-07 20:47:47 CDT) built-in shell (ash)
Enter 'help' for a list of built-in commands.

  _______                     ________        __
 |       |.-----.-----.-----.|  |  |  |.----.|  |_
 |   -   ||  _  |  -__|     ||  |  |  ||   _||   _|
 |_______||   __|_____|__|__||________||__|  |____|
          |__| W I R E L E S S   F R E E D O M
 ATTITUDE ADJUSTMENT (bleeding edge, r26648) ----------
  * 1/4 oz Vodka      Pour all ingredents into mixing
  * 1/4 oz Gin        tin with ice, strain into glass.
  * 1/4 oz Amaretto
  * 1/4 oz Triple sec
  * 1/4 oz Peach schnapps
  * 1/4 oz Sour mix
  * 1 splash Cranberry juice
 -----------------------------------------------------
root@jv-2400-ap1:~# 

comment:60 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

New problem. Backfire r26536

Apr 14 19:22:30 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:30 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:30 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:39 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:39 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:39 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:45 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:45 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:45 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:48 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:48 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:48 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:50 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: authenticated
Apr 14 19:22:50 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: associated (aid 2)
Apr 14 19:22:50 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:51 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPDISCOVER(br-lan) 00:23:76:4e:18:23 
Apr 14 19:22:51 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPOFFER(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:22:51 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPREQUEST(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:22:51 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPACK(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:22:51 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:51 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:51 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:54 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:54 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:54 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:22:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:22:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:22:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:01 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:01 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:01 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:04 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:04 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:04 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:10 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:10 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:10 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:13 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:13 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:13 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:16 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:16 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:16 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:19 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:19 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:19 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:28 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:28 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:28 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:31 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:31 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:31 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:43 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:43 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:43 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:47 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:47 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:47 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:50 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:50 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:51 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
Apr 14 19:23:51 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:23:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:23:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:23:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:03 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:03 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:03 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:12 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:12 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:12 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)

While this happens no connection on wifi

comment:61 Changed 7 years ago by nbd

What kind of client is 00:13:e8:78:33:8b? Weird thing about this is that 00:23:76:4e:18:23 seems to be able to connect just fine and grab a DHCP lease, while the other one's constantly reconnecting.

comment:62 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

00:13 is Intel 00:23 is an Android phone

comment:63 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

And finally Intel coonected, but the other one was losing signal. Finally both reconnected

Apr 14 19:24:18 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:18 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:18 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:26 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
Apr 14 19:24:26 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
Apr 14 19:24:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:41 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: authenticated
Apr 14 19:24:41 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: associated (aid 2)
Apr 14 19:24:41 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:24:42 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPDISCOVER(br-lan) 00:23:76:4e:18:23 
Apr 14 19:24:42 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPOFFER(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:24:42 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPREQUEST(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:24:42 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPACK(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:24:45 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 14 19:24:45 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 14 19:24:46 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 14 19:31:07 OpenWrt authpriv.info dropbear[30958]: Child connection from 192.168.1.2:1205
Apr 14 19:31:08 OpenWrt authpriv.notice dropbear[30958]: password auth succeeded for 'root' from 192.168.1.2:1205
Apr 14 19:31:13 OpenWrt authpriv.info dropbear[30966]: Child connection from 192.168.1.2:1206
Apr 14 19:31:14 OpenWrt authpriv.notice dropbear[30966]: password auth succeeded for 'root' from 192.168.1.2:1206
Apr 14 19:41:20 OpenWrt authpriv.info dropbear[30958]: exit after auth (root): error reading: Connection reset by peer
Apr 14 19:41:24 OpenWrt authpriv.info dropbear[30966]: exit after auth (root): Exited normally
Apr 14 19:42:56 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: authenticated
Apr 14 19:42:56 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: associated (aid 2)
Apr 14 19:42:56 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 WPA: pairwise key handshake completed (RSN)
Apr 14 19:42:56 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPDISCOVER(br-lan) 00:23:76:4e:18:23 
Apr 14 19:42:56 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPOFFER(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:42:56 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPREQUEST(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:42:56 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPACK(br-lan) 192.168.1.131 00:23:76:4e:18:23 
Apr 14 19:47:40 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: group key handshake completed (RSN)
Apr 14 19:47:41 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 WPA: group key handshake completed (RSN)
Apr 14 20:48:59 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 IEEE 802.11: authenticated
Apr 14 20:48:59 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 IEEE 802.11: associated (aid 1)
Apr 14 20:48:59 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 WPA: pairwise key handshake completed (RSN)
Apr 14 20:49:04 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPDISCOVER(br-lan) 00:1d:6a:56:b4:f7 
Apr 14 20:49:04 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPOFFER(br-lan) 192.168.1.157 00:1d:6a:56:b4:f7 
Apr 14 20:49:04 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPDISCOVER(br-lan) 00:1d:6a:56:b4:f7 
Apr 14 20:49:04 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPOFFER(br-lan) 192.168.1.157 00:1d:6a:56:b4:f7 
Apr 14 20:49:04 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPREQUEST(br-lan) 192.168.1.157 00:1d:6a:56:b4:f7 
Apr 14 20:49:04 OpenWrt daemon.info dnsmasq-dhcp[1515]: DHCPACK(br-lan) 192.168.1.157 00:1d:6a:56:b4:f7 

This is what was there after.

comment:64 Changed 7 years ago by jeyjay

nothing new, still the same trouble with r26710. After some time (~6h) is it not possible to reconnect. My mobile phone can't reconnect and doesn't even appear in the log.

Apr 18 21:38:01 XXX daemon.notice hostapd: wlan0: STA 00:1a:73:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Apr 18 21:38:06 XXX daemon.info hostapd: wlan0: STA 00:1a:73:xx:xx:xx IEEE 802.11: disassociated
Apr 18 21:38:07 XXX daemon.info hostapd: wlan0: STA 00:1a:73:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity
Apr 18 21:38:07 XXX daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Apr 18 21:38:11 XXX daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Apr 18 21:42:45 XXX daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Apr 18 21:43:08 XXX daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: disassociated due to inactivity
Apr 18 21:43:09 XXX daemon.info hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity
Apr 18 21:44:09 XXX daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response
Apr 18 21:44:14 XXX daemon.notice hostapd: wlan0: STA 00:1d:fe:xx:xx:xx IEEE 802.11: did not acknowledge authentication response

comment:65 Changed 7 years ago by anonymous

RX DMA still fails to stop on AR9220 in rev. 26717. DMADBG_7=6040, though sometimes 8040, 26040, or 28040. The improvement in r26665 does not help to recover from this state. Let me know if I can provide any more information or if I should open a new ticket. Thanks again.

comment:66 Changed 7 years ago by vaden@…

HTH, I dunno, but we had a case of DMADBG_7=0x000084c0.

regards/Larry

comment:67 follow-up: Changed 7 years ago by jeyjay

Is the RX DAM information somewhere dumped in the debugfs or printed to the syslog?

comment:68 in reply to: ↑ 67 Changed 7 years ago by anonymous

Replying to jeyjay:

Is the RX DAM information somewhere dumped in the debugfs or printed to the syslog?

The DMA errors show up in the syslog. If your problem is similar to mine, then your mobile phone is the device where I would expect to see these errors.

Jan  1 00:17:08 Watson kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00008040
Jan  1 00:17:08 Watson kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up

Regarding the issue, I think there are 2 different triggers. One is right after association when both the client and access point have TX data ready to send in the upper layer. In this case, nothing I've tried short of a power cycle will recover from this error. The other is more difficult to pin down. System logs of routers in an outdoor deployment showed these DMA errors occured without any previous de-authentication or errors of any kind within days. That is, the routers were exchanging data continuously for days without error and then these messages show up at the same time traffic dies. The access point eventually sent a de-auth message (10 minute WPA handshake timeout) and the station then re-associated without having to be power-cycled. Thus, I have seen two problems which trigger radio silence and these errors: one reproducible by running "wifi" until it breaks, and another which happens after running for a few days or weeks. (I've seen that one maybe twice in the last 3 weeks.)

This problem looks like the one from the thread below. I'll see if I can find a way to extend the fixes to work with what I've uncovered, but don't expect anything anytime soon.
http://comments.gmane.org/gmane.linux.kernel.wireless.general/58018

comment:69 Changed 7 years ago by anonymous

I'm the guy with the AR9220 on RouterStation with the DMA issues. They seem to be fixed entirely in my /sbin/wifi - driven test setup now that I have added spin_lock_bh(&sc->rx.rxbuflock) and spin_unlock_bh(&sc->rx.rxbuflock) around all calls to ath9k_hw_setrxabort. Maybe there is a reason why this isn't already done, but I can't say at this point. All I can say is the initial results for me are very positive. Hopefully this helps out the ath9k team in some way.

If you want to test my changes you can save this off in your package/mac80211/patches folder as 599-custom.patch. Be warned, this seems to bring up a warning in kernel/softirq.c:159 which I have not seen before.

--- a/drivers/net/wireless/ath/ath9k/main.c
+++ b/drivers/net/wireless/ath/ath9k/main.c
@@ -810,7 +810,9 @@
 			/* Clear RxAbort bit so that we can
 			 * receive frames */
 			ath9k_setpower(sc, ATH9K_PM_AWAKE);
+			spin_lock_bh(&sc->rx.rxbuflock);
 			ath9k_hw_setrxabort(sc->sc_ah, 0);
+			spin_unlock_bh(&sc->rx.rxbuflock);
 			sc->ps_flags |= PS_WAIT_FOR_BEACON;
 		}
 
@@ -1180,7 +1182,9 @@
 		 */
 		ath9k_ps_wakeup(sc);
 		if (!(sc->sc_ah->caps.hw_caps & ATH9K_HW_CAP_AUTOSLEEP))
+			spin_lock_bh(&sc->rx.rxbuflock);
 			ath9k_hw_setrxabort(sc->sc_ah, 0);
+			spin_unlock_bh(&sc->rx.rxbuflock);
 		if (ieee80211_is_pspoll(hdr->frame_control)) {
 			ath_dbg(common, ATH_DBG_PS,
 				"Sending PS-Poll to pick a buffered frame\n");
@@ -1578,7 +1582,9 @@
 			ah->imask |= ATH9K_INT_TIM_TIMER;
 			ath9k_hw_set_interrupts(ah, ah->imask);
 		}
+		spin_lock_bh(&sc->rx.rxbuflock);
 		ath9k_hw_setrxabort(ah, 1);
+		spin_unlock_bh(&sc->rx.rxbuflock);
 	}
 }
 
@@ -1589,7 +1595,9 @@
 	sc->ps_enabled = false;
 	ath9k_hw_setpower(ah, ATH9K_PM_AWAKE);
 	if (!(ah->caps.hw_caps & ATH9K_HW_CAP_AUTOSLEEP)) {
+		spin_lock_bh(&sc->rx.rxbuflock);
 		ath9k_hw_setrxabort(ah, 0);
+		spin_unlock_bh(&sc->rx.rxbuflock);
 		sc->ps_flags &= ~(PS_WAIT_FOR_BEACON |
 				  PS_WAIT_FOR_CAB |
 				  PS_WAIT_FOR_PSPOLL_DATA |

comment:70 Changed 7 years ago by anonymous

huge flow control error in above code (still works for me), fixed below

@@ -810,7 +810,9 @@
 			/* Clear RxAbort bit so that we can
 			 * receive frames */
 			ath9k_setpower(sc, ATH9K_PM_AWAKE);
+			spin_lock_bh(&sc->rx.rxbuflock);
 			ath9k_hw_setrxabort(sc->sc_ah, 0);
+			spin_unlock_bh(&sc->rx.rxbuflock);
 			sc->ps_flags |= PS_WAIT_FOR_BEACON;
 		}
 
@@ -1179,8 +1181,11 @@
 		 * completed and if needed, also for RX of buffered frames.
 		 */
 		ath9k_ps_wakeup(sc);
-		if (!(sc->sc_ah->caps.hw_caps & ATH9K_HW_CAP_AUTOSLEEP))
+		if (!(sc->sc_ah->caps.hw_caps & ATH9K_HW_CAP_AUTOSLEEP)) {
+			spin_lock_bh(&sc->rx.rxbuflock);
 			ath9k_hw_setrxabort(sc->sc_ah, 0);
+			spin_unlock_bh(&sc->rx.rxbuflock);
+		}
 		if (ieee80211_is_pspoll(hdr->frame_control)) {
 			ath_dbg(common, ATH_DBG_PS,
 				"Sending PS-Poll to pick a buffered frame\n");
@@ -1578,7 +1583,9 @@
 			ah->imask |= ATH9K_INT_TIM_TIMER;
 			ath9k_hw_set_interrupts(ah, ah->imask);
 		}
+		spin_lock_bh(&sc->rx.rxbuflock);
 		ath9k_hw_setrxabort(ah, 1);
+		spin_unlock_bh(&sc->rx.rxbuflock);
 	}
 }
 
@@ -1589,7 +1596,9 @@
 	sc->ps_enabled = false;
 	ath9k_hw_setpower(ah, ATH9K_PM_AWAKE);
 	if (!(ah->caps.hw_caps & ATH9K_HW_CAP_AUTOSLEEP)) {
+		spin_lock_bh(&sc->rx.rxbuflock);
 		ath9k_hw_setrxabort(ah, 0);
+		spin_unlock_bh(&sc->rx.rxbuflock);
 		sc->ps_flags &= ~(PS_WAIT_FOR_BEACON |
 				  PS_WAIT_FOR_CAB |
 				  PS_WAIT_FOR_PSPOLL_DATA |

comment:71 Changed 7 years ago by nbd

Interesting...
The warnings are most likely caused by the part that puts a _bh lock in IRQ context (ath_isr). You can drop it there.
Also, rxbuflock is probably the wrong lock - pcu_lock would be a better choice.
Please try if it still works if you use that one (and drop the lock in irq context).

comment:72 Changed 7 years ago by anonymous

I recant! The rxbuflock does not help, my test setup must have had an incredible run of luck. Normally it fails after a few minutes, but it ran for over an hour yesterday, so I thought my additional locking fixed the problem. My subsequent builds (including trying sc_pcu_lock) failed, so I tried the image that worked so well yesterday. It has the DMA error and I just did not test it enough.

sc_pcu_lock looks to be used in all the right places, so if rxbuflock actually worked, sc_pcu_lock would have been a good replacement. In later experiments I removed my locks from ath_isr and also ath9k_tx (isn't that interrupt-based too?) and still got the kernel/softirq.c:159 warning. ath9k_disable_ps and ath9k_enable_ps are triggered by the ath9k_ops .config function, does that place them in interrupt context too? Can none of these functions calling ath9k_hw_setrxabort hold a spinlock?

The good news is I think I'm on the right course. ath9k_hw_setrxabort appears to control hardware RX without proper locking. Furthermore, it runs twice in AP mode when I run "wifi" versus only once in STA mode and, as far as I can tell, STA mode seems to hang less often. I apologize for the false solution report and I'll give my solutions more staging time before reporting them in the future.

comment:73 Changed 7 years ago by anonymous

I took out some of the powersave code and added a print to ath9k_hw_setrxabort. The RX DMA issues occur even without ath9k_hw_setrxabort, so I got nothing. Sorry for the diversion.

comment:74 Changed 7 years ago by jeyjay

tested r26744 and so far no disconnects after more than one day of uptime (testing ongoing).

So far

ath: Failed to stop TX DMA!

occurred only once in the syslog.

comment:75 Changed 7 years ago by jeyjay

now, after 2 days of uptime, I cannot reconnect.

comment:76 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

Amazing! I have exactly same timing. Disconnect happend 5 min ago.

comment:77 Changed 7 years ago by nbd

Please try trunk r26751

comment:78 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

I am already trying. The one thing I noticed, there are no reconnects with Intel.
So far...

comment:79 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

After some time reconnects started. It is wierd that router works for a couple of days and then it starts. Maybe overflow somewhere?

comment:80 Changed 7 years ago by Dmitry Tunin <hanipouspilot@…>

Apr 25 17:29:26 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 17:29:26 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 17:29:26 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 17:29:26 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPREQUEST(br-lan) 192.168.1.129 00:13:e8:78:33:8b 
Apr 25 17:29:26 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPACK(br-lan) 192.168.1.129 00:13:e8:78:33:8b Natasha
Apr 25 17:55:24 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 WPA: group key handshake completed (RSN)
Apr 25 18:52:50 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:52:50 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:52:50 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:52:51 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPREQUEST(br-lan) 192.168.1.129 00:13:e8:78:33:8b 
Apr 25 18:52:51 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPACK(br-lan) 192.168.1.129 00:13:e8:78:33:8b Natasha
Apr 25 18:53:49 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:53:49 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:53:49 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:53:52 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:53:52 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:53:52 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:53:55 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:53:55 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:53:55 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:53:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:53:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:53:58 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:01 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:01 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:01 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:04 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:04 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:04 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:07 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:08 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:11 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:11 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:11 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:14 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:14 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:14 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:19 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:19 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:19 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:22 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:25 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:28 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:28 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:28 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:31 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:31 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:31 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:34 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:34 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:34 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:37 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:40 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:40 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:40 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:43 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:43 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:43 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:46 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:46 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:46 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:49 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:49 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:49 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:53 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:53 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:53 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:56 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:56 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:56 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:54:59 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:54:59 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:54:59 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:02 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:02 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:02 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:05 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:05 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:05 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:08 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:08 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:08 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:11 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:11 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:11 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:14 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:14 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:14 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:17 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:17 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:17 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:20 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:20 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:20 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:23 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:23 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:23 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:24 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: group key handshake completed (RSN)
Apr 25 18:55:24 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 WPA: group key handshake completed (RSN)
Apr 25 18:55:27 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:27 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:27 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:30 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:30 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:30 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:33 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:36 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:39 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:39 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:39 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 18:55:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: authenticated
Apr 25 18:55:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b IEEE 802.11: associated (aid 1)
Apr 25 18:55:42 OpenWrt daemon.info hostapd: wlan0: STA 00:13:e8:78:33:8b WPA: pairwise key handshake completed (RSN)
Apr 25 19:25:50 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 IEEE 802.11: disassociated due to inactivity
Apr 25 19:25:51 OpenWrt daemon.info hostapd: wlan0: STA 00:1d:6a:56:b4:f7 IEEE 802.11: deauthenticated due to inactivity
Apr 25 19:29:59 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: authenticated
Apr 25 19:29:59 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: associated (aid 1)
Apr 25 19:29:59 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 WPA: pairwise key handshake completed (RSN)
Apr 25 19:30:00 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPDISCOVER(br-lan) 00:23:76:4e:18:23 
Apr 25 19:30:00 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPOFFER(br-lan) 192.168.1.162 00:23:76:4e:18:23 
Apr 25 19:30:00 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPREQUEST(br-lan) 192.168.1.162 00:23:76:4e:18:23 
Apr 25 19:30:00 OpenWrt daemon.info dnsmasq-dhcp[1761]: DHCPACK(br-lan) 192.168.1.162 00:23:76:4e:18:23 

But no DMA error so far

comment:81 Changed 7 years ago by lumute@…

I am experiencing the same reconnects, only mine does not even hold 1 day, I have an scheduled reboot at 5:30am and by noon the reconnects start, may be because I have arour 15 clients? r26751 didn't help... I don't have a way to build from source but is there anythng I can do / provide to help troubleshooting and finding a solution for this?

comment:82 Changed 7 years ago by anonymous

typo, should read 35 wireless clients... BTW, as other people here it seems like Intel clients are good, most of the people experiencing the problem have Dell cards like the 1397. Also, my config is very simple as I am using it as AP only and I have two wireless networks (Main + guest) both using "mixed WPA/WPA2 PSK (TKIP, CCMP)".

comment:83 Changed 7 years ago by nbd

Please try using CCMP only instead of mixed TKIP+CCMP

comment:84 Changed 7 years ago by anonymous

Cool, it seems like at least 5 of my clients are connecting using TKIP as their handshake says WPA instead of RSN... I'll fix their wireless profiles, give this a try and report back...

Thanks!

comment:85 Changed 7 years ago by jeyjay

still the same trouble with r26751. Encryption is (and has been all the time) WPA2 PSK (CCMP). I have problems with all kind of clients including mobile phones, laptops with broadcom, intel, ....

comment:86 Changed 7 years ago by jeyjay

... and connection was faster before r26750

comment:87 Changed 7 years ago by nbd

When you can't connect, please create a monitor mode interface with

iw wlan0 interface add mon0 type monitor

then capture some packets while trying to connect with a client, using

tcpdump -ni mon0 -s 2000 -w /tmp/file.pcap

Then send me that file

comment:88 Changed 7 years ago by jeyjay

after

iw wlan0 interface add mon0 type monitor

I got the message

tcpdump: mon0: That device is not up

Anyway, a monitor interface called mon.wlan0 is already there and is working.

Now I have to wait for the disconnect to appear...

comment:89 Changed 7 years ago by nbd

forgot to mention that you need to bring mon0 up using

ifconfig mon0 up

do not use mon.wlan0, it is not a real monitor interface and it will not show all the relevant data.

comment:90 Changed 7 years ago by jeyjay

Thank you for the info. I tried

ifup mon0

but only

ifconfig mon0 up

will do the work.

comment:91 Changed 7 years ago by Pilot6 <hanipouspilot@…>

I turn off Intel client for a couple of days. There was only one wireless client.
It worked OK, but finally got

May  2 10:53:38 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:38 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028020
May  2 10:53:38 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:38 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:38 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:39 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:39 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:39 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:39 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:39 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:39 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:39 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:39 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:40 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:40 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:40 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:40 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:40 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:40 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:40 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:40 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:41 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:41 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:41 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:41 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:41 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:41 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:41 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:41 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:42 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:42 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:42 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:42 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:42 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:42 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:42 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:42 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:43 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:43 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:43 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:43 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:43 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:43 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:43 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:43 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:44 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:44 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:44 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:44 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:44 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:44 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:44 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:44 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:45 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:45 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:45 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:45 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:45 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:45 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:45 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:45 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:46 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:46 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:46 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:46 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:46 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:46 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:46 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:46 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:47 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028020
May  2 10:53:47 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:47 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00028020
May  2 10:53:47 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:47 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:47 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:47 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:47 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:48 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:48 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:48 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:48 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:48 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:48 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:48 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:48 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:49 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:49 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:49 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:49 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:49 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:49 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:49 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:49 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:49 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:49 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:50 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:50 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:50 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:50 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:50 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:50 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:50 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:50 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:51 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:51 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:51 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:51 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:51 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:51 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:51 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:51 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:52 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:52 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:52 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00024020
May  2 10:53:52 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:52 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00026020
May  2 10:53:52 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:53:52 OpenWrt kern.err kernel: ath: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x42000020 DMADBG_7=0x00006020
May  2 10:53:52 OpenWrt kern.err kernel: ath: Could not stop RX, we could be confusing the DMA engine when we start RX up
May  2 10:57:21 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: disassociated due to inactivity
May  2 10:57:22 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: deauthenticated due to inactivity
May  2 11:01:50 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: authenticated
May  2 11:01:50 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 IEEE 802.11: associated (aid 1)
May  2 11:01:51 OpenWrt daemon.info hostapd: wlan0: STA 00:23:76:4e:18:23 WPA: pairwise key handshake completed (RSN)

It always happens after a long period of normal work. Maybe there is some variable which gets overflow.

comment:92 Changed 7 years ago by jeyjay

still the same trouble with r27004.

BTW: Felix, did you receive the pcap-files?

comment:93 Changed 7 years ago by ternyk@…

I've the same problem: Tp-Link 1043ND + Intel 2200bg mini PCI (Dell C610, Windows XP) on r26962.

...
May 26 11:14:16 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx IEEE 802.11: deauthenticated due to local deauth request
May 26 11:14:16 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx IEEE 802.11: authenticated
May 26 11:14:16 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx IEEE 802.11: associated (aid 1)
May 26 11:14:16 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx WPA: pairwise key handshake completed (RSN)
May 26 11:14:19 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx IEEE 802.11: disassociated
May 26 11:14:19 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx IEEE 802.11: authenticated
May 26 11:14:19 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx IEEE 802.11: associated (aid 1)
May 26 11:14:19 Gargoyle daemon.info hostapd: wlan0: STA 00:0e:xx:xx:xx:xx WPA: received EAPOL-Key 2/4 Pairwise with unexpected replay counter
...
[repeated every about few seconds]

with config:

config 'wifi-device' 'radio0'
        option 'type' 'mac80211'
        option 'macaddr' '54:e6:xx:xx:xx:xx'
        option 'hwmode' '11gn'     #the same also if I disable N, so with '11g'
        option 'htmode' 'HT20'
        list 'ht_capab' 'SHORT-GI-40'
        list 'ht_capab' 'DSSS_CCK-40'
        option 'channel' '8'

config 'wifi-iface' 'apcfg'
        option 'device' 'radio0'
        option 'mode' 'ap'
        option 'network' 'lan'
        option 'ssid' '****'
        option 'encryption' 'psk2'
        option 'key' '******'

comment:94 Changed 7 years ago by PChap

Looks like possibly this /changeset/26985.html will fix it? I've been getting the same on 1043nd.

comment:95 follow-up: Changed 7 years ago by nbd

please try latest trunk, lots of fixes went in, some of which might be related.

comment:96 in reply to: ↑ 95 Changed 7 years ago by Pilot6 <hanipouspilot@…>

Now I test trunk r27411. I got a new error message which did not appear before.

Jul  4 17:29:57 Openwrt kern.warn kernel: ------------[ cut here ]------------
Jul  4 17:29:57 Openwrt kern.warn kernel: WARNING: at /home/pilot6/Openwrt/trunk/build_dir/linux-ar71xx_generic/compat-wireless-2011-06-22/net/mac80211/rx.c:2916 0x80c19720()
Jul  4 17:29:57 Openwrt kern.warn kernel: Rate marked as an HT rate but passed status->rate_idx is not an MCS index [0-76]: 77 (0x4d)
Jul  4 17:29:57 Openwrt kern.warn kernel: Modules linked in: usblp ledtrig_usbdev ledtrig_heartbeat nf_nat_irc nf_conntrack_irc nf_nat_ftp nf_conntrack_ftp ipt_MASQUERADE iptable_nat nf_nat xt_conntrack xt_NOTRACK iptable_raw xt_state nf_conntrack_ipv4 nf_defrag_ipv4 nf
Jul  4 17:29:57 Openwrt kern.warn kernel: Call Trace:[<80184a30>] 0x80184a30
Jul  4 17:29:57 Openwrt kern.warn kernel: [<8024eb30>] 0x8024eb30
Jul  4 17:29:57 Openwrt kern.warn kernel: [<8024eb30>] 0x8024eb30
Jul  4 17:29:57 Openwrt kern.warn kernel: [<80074e70>] 0x80074e70
Jul  4 17:29:57 Openwrt kern.warn kernel: [<80c19720>] 0x80c19720
Jul  4 17:29:57 Openwrt kern.warn kernel: [<80074f24>] 0x80074f24
Jul  4 17:29:57 Openwrt kern.warn kernel: [<800d1164>] 0x800d1164

comment:97 Changed 7 years ago by nbd

  • Resolution set to duplicate
  • Status changed from reopened to closed

this ticket is getting messy, please do not reopen it or add to it. if you're thinking about reopening, please find a ticket that accurately describes your issue, or make a new one instead.

comment:98 Changed 7 years ago by jeyjay

...finally I solved the problem by disabling WMM. See https://forum.openwrt.org/viewtopic.php?id=27953 for more information.

I say this to help solving the primary ticket. I think here are several problems mixed up which are leading to similar effects.

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.