Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FS#13 - Ath9k AP stays up for connected clients but doesn't show in scan on new ones #5480

Closed
openwrt-bot opened this issue Jun 16, 2016 · 51 comments
Labels

Comments

@openwrt-bot
Copy link

@openwrt-bot openwrt-bot commented Jun 16, 2016

Borromini:

After a while the AP disappears from the list of available networks when scanned. Connected clients keep seeing the AP, and connectivity remains, but new clients do not see the AP.

I have experienced this both on a TL-WR1043ND v1 (2,4 GHz ath9k) and on a WNDR3700 (5 GHz ath9k).

  • On the TP-Link, I checked 'wifi status', which reported the AP as still being up (!). However, it did not turn up in an AP scan. The logs (dmesg, logread) did not show anything amiss (since the logs go only back so far it might have been too late since I noticed it).
  • On the Netgear, my laptop (Intel AC8260 wireless) and smartphone (Xperia Z3 Compact) still saw the 5 GHz AP, and wireless worked still fine; I started my tablet (Nexus 7 2013), which did not see the AP. This happened yesterday evening (June 15th) around 22:30, but the logs do not show anything peculiar. 5 GHz AP is wlan1.

Logs for the WNDR3700:

  • [[http://ix.io/Tvi|dmesg]]
  • [[http://ix.io/Tvk|logread]]
@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jun 17, 2016

Borromini:

I see I forgot to include the revisions - this happens with r321 running on he TL-WR1043ND v1, and r607 on the WNDR3700. Will update to r711 to see if this solves anything.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jun 18, 2016

Borromini:

I have an update on the TL-WR1043ND. Loaded r711 onto it this night, after 9h of uptime the AP does not show up in scans anymore.

Logs:

  • [[http://ix.io/Uc1|Wifi status]]
  • [[http://ix.io/Uc2|dmesg]]
  • [[http://ix.io/Uc3|logread]]

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jun 23, 2016

Bluse:

Hi all,

I can confirm the symptoms of the disapearing AP functionality after a couple of hours as you've discribed on my router as well.

Hardware: TP-Link TL-WR1043N/ND v3
Lede version: r580
wireless config: ap mode (details given under [1])

Symptoms: after a couple of hours proper AP functionality, the ssid of the same router disapears, new clients are not able to connect to this AP

Troubleshooting:

  • issuing the command wifi does not bring back the AP

  • creating am monitor device with iw phy phy0 add interface mon0 type monitor leads to the error output: command failed: Too many open files in system (-23), after increasing the max_files by issuing echo 32768 > /proc/sys/fs/file-max the monitor device creation with iw works, but after bringing up mon0 by ifconfig mon0 up the mon0 inferface does not show any increase in packet count (it stays at 0) nor any output via tcpdump -nei mon0

  • output of dmesg shows some potential problem user.notice : Command failed: Not found, but I have not yet investigated if a wifi config is triggering this, maybe someone sees an issue under [1]

  • a second wifi router on the same channel with an monitor interface does not receive any beacons from the TPLink 1043

educated guess:

  • beacons seem to get stuck after some hours in AP mode and are not been sent out anymore

workaround:

  • wifi
  • hard reboot

[1] cat /etc/config/wireless

config wifi-device 'radio0' option type 'mac80211' option channel '6' option hwmode '11g' option path 'platform/qca955x_wmac' option htmode 'HT20' option txpower '18' option distance '1500' option country 'HT' option frag '2346' option rts '2346' option basic_rate '6000 12000 24000' option disabled '0'

config wifi-iface
option device 'radio0'
option network 'lan'
option mode 'ap'
option ssid 'test_lede'
option encryption 'psk2'
option key 'test123456789'
option mcast_rate '6000'
option disassoc_low_ack '1'
option skip_inactivity_poll '0'

Greetings from Berlin
Bluse

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jun 29, 2016

Bluse:

Hi all,

A additional observation I made is:
If the ap in question is in such a mode where no beacons are send and WiFi is not working anymore, the OS does not show any increase in interrupt counts for the ath9k card. You can check this by triggering cat /proc/interrupts and watch the line with ath9k, e.g.:
CPU0
4: 10907 MIPS 4 eth0
5: 524477 MIPS 5 eth1
7: 5958616 MIPS 7 timer
11: 26 MISC serial
47: 121776 dummy ath9k
48: 0 dummy ehci_hcd:usb1
49: 0 dummy ehci_hcd:usb2
ERR: 738

Can anyone confirm this "stop if interrupts" on his/her side as well ?

Bye Bluse

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jun 29, 2016

Bluse:

Hi all,

Just tested another mips router TPLink CPE210 (ath9k based) and I do see the same not-working AP functionality sometimes. At the moment I can not reproduce the stuck-AP in dedicated way, so the "sometimes" means after some hours or right after reboot.
The interrupt counter does not increase and stucks at count 27, which is quite low and could indicate that right after initialising the device by the OS, it got stuck.

LEDE version 811

Greetings Bluse

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jun 29, 2016

Bluse:

Hi all,

I was able to find a way to reproduce the issue with "not interrupt increase" for ath9k and hence AP stops from operation.

steps to reproduce on TPLink CPE210 with LEDE version 811:

  • for better observability just establish two ssh session to your router, side-by-side

  • in window A watch the interrupt counter for ath9k by while true; do cat /proc/interrupts ; sleep 1; done

  • in window B issue wifi severale times. After 2-4 "wifi" triggers, I am able to stop the interrupt counter and the overall wifi and after another 2-4 "wifi" triggers the interrupt counter increases its count again and wifi is back.

dmesg output:
to get some debug output from ath9k, I used echo "0x00000793" > /sys/kernel/debug/ieee80211/phy0/ath9k/debug, which shows:
[[http://pastebin.com/38EMU31e|dmesg output with ath9k debug]]

Can someone test this steps and report if the same is observeable ?

Bye Bluse

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jul 2, 2016

Borromini:

I'm running 811 as well, I have not observed any issues anymore with my WNDR3700 (5 GHz AP). The TL-WR1043ND seems on its way out, it looks like there may also a hardware problem on my side. I will do some testing like Bluse-Blue suggests when I get the chance (but that won't be for a few weeks).

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jul 2, 2016

hojuruku:

https://dev.openwrt.org/ticket/22709

I reported the same in openwrt land.

I've made a debug kernel install with ath9k debug, no stripping on the kernel, and kernel memory dump.

willing to let nbd ssh in (contact me on irc) when it dies.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jul 9, 2016

hojuruku:

Don't know if this helps but I get this just before drop outs. It's been reported as such elsewhere. It's from wpad-mini in debug 0

Seems related to this:
https://dev.openwrt.org/ticket/22086#comment:12
https://community.sophos.com/products/unified-threat-management/f/60/t/56385 similar symptoms.
http://marc.info/?l=linux-wireless&m=130280925115836
Oh and a possible $250 bounty for this "LOW PRIORITY" issue
https://www.bountysource.com/issues/32309542-no-connection-on-wlan-in-2-4g

r857 but updating shortly then I'll get the debug logs.

Sat Jul 9 19:27:35 2016 daemon.debug hostapd: wlan0: STA 24:fd:52:39:20:40 IEEE 802.11: hostapd_public_action - action=0
Sat Jul 9 19:27:35 2016 daemon.debug hostapd: wlan0: STA 24:fd:52:39:20:40 IEEE 802.11: handle_action - unknown action category 4 or invalid frame
Sat Jul 9 19:28:48 2016 daemon.debug hostapd: wlan0: STA 24:fd:52:39:20:40 IEEE 802.11: hostapd_public_action - action=0
Sat Jul 9 19:28:48 2016 daemon.debug hostapd: wlan0: STA 24:fd:52:39:20:40 IEEE 802.11: handle_action - unknown action category 4 or invalid frame
Sat Jul 9 19:30:05 2016 daemon.debug hostapd: wlan0: STA 24:fd:52:39:20:40 IEEE 802.11: hostapd_public_action - action=0
Sat Jul 9 19:30:05 2016 daemon.debug hostapd: wlan0: STA 24:fd:52:39:20:40 IEEE 802.11: handle_action - unknown action category 4 or invalid frame

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jul 13, 2016

hojuruku:

I've tried nbd's staging build a few times.

I'm out. I'm setting up a new router and going back to FACTORY FIRMWARE for the TP-Link. It's not NBD's fault, last time we had all this trouble was with trunk 3 years ago and it took ages to sort out, something about a buggy wifi mac.
https://dev.openwrt.org/ticket/11862

Openwrt trunk from 1-2 years ago worked like a charm. There is definitely some regression issues. Please consider picking a good time in ath9k's period from 1-2 years ago before all the new quallcomm SOCs were added and make it as ath9k (old) and let people choose in make menuconfig after up-porting it to Kernel 4.4. Then wash your hands of this.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jul 26, 2016

guenti_r:

On my TP-Link TL-WDR4900 v1 with LEDE r1-r1117 Wifi (ath9k 2.4 & 5 Ghz) is rock solid.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jul 30, 2016

Borromini:

I have tried to replicate Bluse-Blue's observations. The TL-WR1043ND v1 here has been up for over 11 days, I don't know when wifi crapped out (it's at my brother's place) - but it typically does so fairly early after (re)booting.

A single 'wifi' command brought ath9k back up. I have no /sys/kernel/debug/ieee80211/phy0/ath9k/debug file (this is my own build off the vanilla LEDE main git tree).

Prior to running 'wifi', the ath9k interrupt was stuck on 2460703. After running it, the interrupt value (I'm not too familiar with this) steadily increases.

If there's anything else I can check - let me know. This was tested on Lede r1003.

Edit: I forgot I had ath9k debugging disabled, will rebuild and test again.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Aug 2, 2016

nbd:

Please try the latest version from my staging tree:
https://git.lede-project.org/?p=lede/nbd/staging.git;a=summary

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Aug 4, 2016

stefanct:

I have the same problem on my TL-WR1043ND v1. First I thought it is related to WDS, then to ANI, but apparently it must be something deeper. Also, FWIW, I have tested 1.7.1 and 1.9.1 of Gargoyle and it does not show any problems on my hardware!

No change with Felix' branch for me.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Aug 24, 2016

glycoknob:

I can also confirm the issue on a 1043NDv1 - running r1396. Nothing in the logs. AP does not appear in scan anymore.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Aug 24, 2016

glycoknob:

The issue is reproducible for me when I have 2 clients that both do downloads e.g.

running: wget -O /dev/null http://speed.hetzner.de/100MB.bin

it's enough to have a have a few megabit downstream on both clients and the issue starts immediatly.

Now on r1435 - here is the hostapd logfile at log_level=0 but nothing interesting to see:

Wed Aug 24 19:34:45 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.1X: authorizing port Wed Aug 24 19:34:45 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: pairwise key handshake completed (RSN) Wed Aug 24 19:36:39 2016 daemon.debug hostapd: wlan0: WPA rekeying GTK Wed Aug 24 19:36:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: sending 1/2 msg of Group Key Handshake Wed Aug 24 19:36:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: received EAPOL-Key frame (2/2 Group) Wed Aug 24 19:36:39 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: group key handshake completed (RSN) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-AUTHENTICATE.indication(e8:de:27:19:b9:17, OPEN_SYSTEM) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-DELETEKEYS.request(e8:de:27:19:b9:17) Wed Aug 24 19:38:22 2016 daemon.info hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: authenticated Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: association OK (aid 2) Wed Aug 24 19:38:22 2016 daemon.info hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: associated (aid 2) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-ASSOCIATE.indication(e8:de:27:19:b9:17) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-DELETEKEYS.request(e8:de:27:19:b9:17) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: binding station to interface 'wlan0' Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: event 1 notification Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: start authentication Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.1X: unauthorizing port Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: sending 1/4 msg of 4-Way Handshake Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: received EAPOL-Key frame (2/4 Pairwise) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: sending 3/4 msg of 4-Way Handshake Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: received EAPOL-Key frame (4/4 Pairwise) Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.1X: authorizing port Wed Aug 24 19:38:22 2016 daemon.info hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: pairwise key handshake completed (RSN) Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: event 2 notification Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.1X: unauthorizing port Wed Aug 24 19:38:39 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: disassociated Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DISASSOCIATE.indication(90:68:c3:aa:b4:80, 1) Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:38:40 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE) Wed Aug 24 19:38:40 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DEAUTHENTICATE.indication(90:68:c3:aa:b4:80, 2) Wed Aug 24 19:38:40 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:38:46 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:38:46 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM) Wed Aug 24 19:38:46 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:38:47 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response Wed Aug 24 19:38:51 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:38:51 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM) Wed Aug 24 19:38:51 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:38:52 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response Wed Aug 24 19:38:58 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:38:58 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM) Wed Aug 24 19:38:58 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:38:59 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response Wed Aug 24 19:39:10 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:39:10 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM) Wed Aug 24 19:39:10 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:39:11 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: disconnected due to excessive missing ACKs Wed Aug 24 19:39:11 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response Wed Aug 24 19:39:12 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DISASSOCIATE.indication(90:68:c3:aa:b4:80, 34) Wed Aug 24 19:39:12 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:39:13 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:39:13 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM) Wed Aug 24 19:39:13 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:39:14 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response Wed Aug 24 19:39:17 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system) Wed Aug 24 19:39:17 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM) Wed Aug 24 19:39:17 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80) Wed Aug 24 19:39:18 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Sep 4, 2016

nbd:

Please try the latest version

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Sep 12, 2016

gwlim:

I am suspecting the changes to the ath9k wifi stack revived the hardware bug with the older atheros chips namely AR9132.
https://dev.openwrt.org/ticket/11862
Tested the latest LEDE Trunk on newer ath9k chips this does not happen.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Sep 12, 2016

glycoknob:

Problem is still there with r1586. Also connected clients don't stay connected and loose the connection after a while!

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Oct 6, 2016

Bluse:

Hi all,

For my this problem ist gone with the latest power-safe changes to ath9k.
Are you still have this kind of problems with latest Lede trunk ?

Greetings from Berlin
Thomas

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Oct 7, 2016

IronicSven:

Hi Thomas,

I just tested r1811 on my TL-WR1043N/ND v1 and the problem still exists for me. My client looses the connection after a while and the AP is not visible anymore.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Oct 15, 2016

szatam:

Hey everyone,

Having the issue here as well. r1845 on a TL-WR1043N/ND v1.
Log shows "did not acknowledge authentication response" wifi-related messages.
Issuing "wifi" helps in the beginning, but after a while the wireless network completely disappears, combined with ping delays and packet loss on the wired interface as well.

Dmesg often shows random page faults (busybox, dnsmasq, dropbear, etc..):
[11948.873633] do_page_fault(): sending SIGSEGV to hotplug-call for invalid read access from 000000ec
[11948.882704] epc = 00439ff1 in busybox[400000+4a000]
[11948.887665] ra = 00439fe5 in busybox[400000+4a000]

Using the trunk build, zram is NOT enabled.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 27, 2016

nbd:

Please try the latest version

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 27, 2016

IronicSven:

Hi Felix,

the wifi still stops working and disappears on my 1043nd with the latest snapshot.

I tried to debug it last weekend and discovered it only happens under a few seconds of high load. Therefore I can trigger it with iperf.

I just build an image from https://git.lede-project.org/source.git with ath debugging enabled and this is what I captured:

root@FlensNet:~# uci set wireless.radio0.log_level=0 root@FlensNet:~# uci commit wireless root@FlensNet:~# wifi up root@FlensNet:~# echo 0x00000409 > /sys/kernel/debug/ieee80211/phy0/ath9k/debug root@FlensNet:~# logread -f

now I start iperf

Tue Dec 27 17:15:39 2016 kern.debug kernel: [ 113.787634] ath: phy0: NF calibrated [ctl] [chain 0] is -90
Tue Dec 27 17:15:39 2016 kern.debug kernel: [ 113.793249] ath: phy0: NF calibrated [ctl] [chain 1] is -87
Tue Dec 27 17:15:39 2016 kern.debug kernel: [ 113.798867] ath: phy0: NF calibrated [ctl] [chain 2] is -86
Tue Dec 27 17:16:09 2016 kern.debug kernel: [ 143.797558] ath: phy0: NF calibrated [ctl] [chain 0] is -89
Tue Dec 27 17:16:09 2016 kern.debug kernel: [ 143.803192] ath: phy0: NF calibrated [ctl] [chain 1] is -88
Tue Dec 27 17:16:09 2016 kern.debug kernel: [ 143.808830] ath: phy0: NF calibrated [ctl] [chain 2] is -85
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.807130] ath: phy0: tx hung, resetting the chip
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.818006] ath: phy0: Failed to stop TX DMA, queues=0x002!
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.830165] ath: phy0: NF calibrated [ctl] [chain 0] is -90
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.835773] ath: phy0: NF calibrated [ctl] [chain 1] is -86
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.841418] ath: phy0: NF calibrated [ctl] [chain 2] is -87
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.847021] ath: phy0: reset MAC via external reset
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.902661] ath: phy0: ah->misc_mode 0xc
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.909136] ath: phy0: enabling IQ Calibration
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.913602] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:16:26 2016 kern.debug kernel: [ 159.918872] ath: phy0: Setting CFG 0x10a
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 160.937114] ath: phy0: tx hung, resetting the chip
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 160.948101] ath: phy0: NF calibrated [ctl] [chain 0] is -87
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 160.953716] ath: phy0: NF calibrated [ctl] [chain 1] is -87
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 160.959372] ath: phy0: NF calibrated [ctl] [chain 2] is -84
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 160.995701] ath: phy0: ah->misc_mode 0xc
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 161.002169] ath: phy0: enabling IQ Calibration
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 161.006631] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:16:27 2016 kern.debug kernel: [ 161.011903] ath: phy0: Setting CFG 0x10a
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.027114] ath: phy0: tx hung, resetting the chip
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.032452] ath: phy0: NF calibrated [ctl] [chain 0] is -89
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.038108] ath: phy0: NF calibrated [ctl] [chain 1] is -86
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.043708] ath: phy0: NF calibrated [ctl] [chain 2] is -85
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.080043] ath: phy0: ah->misc_mode 0xc
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.086484] ath: phy0: enabling IQ Calibration
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.090978] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:16:28 2016 kern.debug kernel: [ 162.096225] ath: phy0: Setting CFG 0x10a

about now iperf hangs and the wifi symbol on my android device disappears

Tue Dec 27 17:16:58 2016 kern.debug kernel: [ 192.096793] ath: phy0: 0: Chn 0 pmi=0x000c8415;pmq=0x000a4731;iqcm=0x00002272;
Tue Dec 27 17:16:58 2016 kern.debug kernel: [ 192.104070] ath: phy0: 0: Chn 1 pmi=0x000a4d43;pmq=0x0009537b;iqcm=0x00006dfd;
Tue Dec 27 17:16:58 2016 kern.debug kernel: [ 192.111352] ath: phy0: 0: Chn 2 pmi=0x0009cd18;pmq=0x00090419;iqcm=0xffff8061;
Tue Dec 27 17:16:58 2016 kern.debug kernel: [ 192.118615] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:16:59 2016 kern.debug kernel: [ 193.116761] ath: phy0: 1: Chn 0 pmi=0x002bc89c;pmq=0x001a2fdf;iqcm=0xfffe3b89;
Tue Dec 27 17:16:59 2016 kern.debug kernel: [ 193.124030] ath: phy0: 1: Chn 1 pmi=0x0020d8ad;pmq=0x001f60fd;iqcm=0x000658ad;
Tue Dec 27 17:16:59 2016 kern.debug kernel: [ 193.131310] ath: phy0: 1: Chn 2 pmi=0x00162d15;pmq=0x001f0b19;iqcm=0xfffe1ff1;
Tue Dec 27 17:16:59 2016 kern.debug kernel: [ 193.138578] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:17:04 2016 kern.debug kernel: [ 198.436702] ath: phy0: 2: Chn 0 pmi=0x003587c7;pmq=0x002390be;iqcm=0xfffe079e;
Tue Dec 27 17:17:04 2016 kern.debug kernel: [ 198.443976] ath: phy0: 2: Chn 1 pmi=0x002afd77;pmq=0x00289f9a;iqcm=0x00066de2;
Tue Dec 27 17:17:04 2016 kern.debug kernel: [ 198.451265] ath: phy0: 2: Chn 2 pmi=0x003633fd;pmq=0x003e9e1f;iqcm=0xfffda432;
Tue Dec 27 17:17:04 2016 kern.debug kernel: [ 198.458533] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:17:07 2016 kern.debug kernel: [ 201.056653] ath: phy0: 3: Chn 0 pmi=0x0040e147;pmq=0x002b71ed;iqcm=0xfffd09c2;
Tue Dec 27 17:17:07 2016 kern.debug kernel: [ 201.063932] ath: phy0: 3: Chn 1 pmi=0x002c7c11;pmq=0x002a384d;iqcm=0x0006e5b0;
Tue Dec 27 17:17:07 2016 kern.debug kernel: [ 201.071211] ath: phy0: 3: Chn 2 pmi=0x00376cae;pmq=0x004011a0;iqcm=0xfffdccab;
Tue Dec 27 17:17:07 2016 kern.debug kernel: [ 201.078476] ath: phy0: starting IQ Mismatch Calibration
Tue Dec 27 17:17:08 2016 kern.debug kernel: [ 201.876642] ath: phy0: 4: Chn 0 pmi=0x004acdd9;pmq=0x00345105;iqcm=0xfffcde5a;
Tue Dec 27 17:17:08 2016 kern.debug kernel: [ 201.883919] ath: phy0: 4: Chn 1 pmi=0x0035ff9c;pmq=0x00325ce8;iqcm=0x0006fda4;
Tue Dec 27 17:17:08 2016 kern.debug kernel: [ 201.891208] ath: phy0: 4: Chn 2 pmi=0x003ccf87;pmq=0x0045b01c;iqcm=0xfffda1a7;

I hope this helps.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 27, 2016

nbd:

Does the disconnect happen around the time right before or after your "about now" line?

By the way, I pushed another AR913x specific stability fix, so please test the latest version.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 27, 2016

IronicSven:

Hi Felix,

wifi disappears before the "about now" line.

I tested your fix but it still happens.

root@FlensNet:~# cat /etc/os-release | grep BUILD BUILD_ID="r2695-c9c68c7" root@FlensNet:~# echo 0x00000409 > /sys/kernel/debug/ieee80211/phy0/ath9k/debug root@FlensNet:~# logread -f Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.597074] ath: phy0: 48: Chn 0 pmi=0x00cc6dd7;pmq=0x00d047cf;iqcm=0xffff1388; Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.604442] ath: phy0: 48: Chn 1 pmi=0x0104228c;pmq=0x00eb9d9a;iqcm=0xfffdae7c; Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.611815] ath: phy0: 48: Chn 2 pmi=0x013c3eec;pmq=0x0142fe99;iqcm=0xfffeef20; Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.619168] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.717104] ath: phy0: 49: Chn 0 pmi=0x00d865b0;pmq=0x00dad7e4;iqcm=0xfffe5f35; Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.724481] ath: phy0: 49: Chn 1 pmi=0x010d176a;pmq=0x00f369c5;iqcm=0xfffd61ac; Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.731856] ath: phy0: 49: Chn 2 pmi=0x01451c01;pmq=0x014d25f9;iqcm=0xfffee38d; Tue Dec 27 22:36:39 2016 kern.debug kernel: [ 109.739210] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.637059] ath: phy0: 50: Chn 0 pmi=0x00e3188f;pmq=0x00e4edc4;iqcm=0xfffd27d3; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.644426] ath: phy0: 50: Chn 1 pmi=0x0113424e;pmq=0x00f92d68;iqcm=0xfffd8139; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.651794] ath: phy0: 50: Chn 2 pmi=0x015af9d5;pmq=0x015cc847;iqcm=0xfffe245f; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.659149] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.757047] ath: phy0: 51: Chn 0 pmi=0x00e661cc;pmq=0x00e8701c;iqcm=0xfffc6071; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.764408] ath: phy0: 51: Chn 1 pmi=0x01165e0d;pmq=0x00fc7ba3;iqcm=0xfffdb8ea; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.771779] ath: phy0: 51: Chn 2 pmi=0x015e6f6a;pmq=0x0160ab0c;iqcm=0xfffdcf18; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 110.779137] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.377047] ath: phy0: 52: Chn 0 pmi=0x00e6b8e9;pmq=0x00e8ddf0;iqcm=0xfffc6d10; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.384413] ath: phy0: 52: Chn 1 pmi=0x01170c3b;pmq=0x00fd05e1;iqcm=0xfffdc01a; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.391782] ath: phy0: 52: Chn 2 pmi=0x015f3c24;pmq=0x01615d16;iqcm=0xfffdd31e; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.399140] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.497086] ath: phy0: 53: Chn 0 pmi=0x00f7b8af;pmq=0x00f84a3d;iqcm=0xfffd841d; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.504467] ath: phy0: 53: Chn 1 pmi=0x01205f65;pmq=0x0104a77a;iqcm=0xfffe5277; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.511835] ath: phy0: 53: Chn 2 pmi=0x016bbd3b;pmq=0x016d8fbd;iqcm=0xfffee59d; Tue Dec 27 22:36:40 2016 kern.debug kernel: [ 111.519185] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.617103] ath: phy0: 54: Chn 0 pmi=0x01042b62;pmq=0x01065bce;iqcm=0xfffc28af; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.624479] ath: phy0: 54: Chn 1 pmi=0x012a3599;pmq=0x01103fa7;iqcm=0xfffdfe14; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.631843] ath: phy0: 54: Chn 2 pmi=0x0174f322;pmq=0x0178e0f5;iqcm=0xfffdd605; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.639194] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.737089] ath: phy0: 55: Chn 0 pmi=0x01081c98;pmq=0x010b0ea0;iqcm=0xfffc07ce; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.744455] ath: phy0: 55: Chn 1 pmi=0x0133cc97;pmq=0x011ab0ce;iqcm=0xfffe1832; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.751825] ath: phy0: 55: Chn 2 pmi=0x017d2d36;pmq=0x01827e6a;iqcm=0xfffd8223; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.759176] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.857085] ath: phy0: 56: Chn 0 pmi=0x012b4707;pmq=0x012955f2;iqcm=0x000307d0; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.864461] ath: phy0: 56: Chn 1 pmi=0x013fb24d;pmq=0x01242b63;iqcm=0xfffe5282; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.871825] ath: phy0: 56: Chn 2 pmi=0x0187e0f7;pmq=0x018ab1a2;iqcm=0xfffe1af8; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.879175] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.977102] ath: phy0: 57: Chn 0 pmi=0x01393f73;pmq=0x013520a5;iqcm=0x0002342e; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.984480] ath: phy0: 57: Chn 1 pmi=0x01492abb;pmq=0x012d9a75;iqcm=0xfffd6bb3; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.991851] ath: phy0: 57: Chn 2 pmi=0x0190b9a4;pmq=0x0193d2d1;iqcm=0xfffd9fa1; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 111.999204] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.097087] ath: phy0: 58: Chn 0 pmi=0x0143f966;pmq=0x013e01f8;iqcm=0x00002161; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.104463] ath: phy0: 58: Chn 1 pmi=0x0150a73c;pmq=0x0138518b;iqcm=0xfffe3bca; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.111832] ath: phy0: 58: Chn 2 pmi=0x0199b058;pmq=0x019fcfe2;iqcm=0xfffb4efb; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.119184] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.217087] ath: phy0: 59: Chn 0 pmi=0x014bd240;pmq=0x014a1bf3;iqcm=0x00015ef4; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.224465] ath: phy0: 59: Chn 1 pmi=0x015cc1c1;pmq=0x013e8a34;iqcm=0xfffd658a; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.231833] ath: phy0: 59: Chn 2 pmi=0x01a35247;pmq=0x01a8048f;iqcm=0xfffd6ee5; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.239183] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.337224] ath: phy0: 60: Chn 0 pmi=0x0154a60b;pmq=0x01544796;iqcm=0x0002c438; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.344604] ath: phy0: 60: Chn 1 pmi=0x0167db5e;pmq=0x01473471;iqcm=0xfffca7bd; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.351994] ath: phy0: 60: Chn 2 pmi=0x01ae755b;pmq=0x01b2375b;iqcm=0xfffe4400; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.359349] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.457148] ath: phy0: 61: Chn 0 pmi=0x01602116;pmq=0x015daf22;iqcm=0x00025bf5; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.464523] ath: phy0: 61: Chn 1 pmi=0x01733d4f;pmq=0x0152b57e;iqcm=0xfffb6196; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.471908] ath: phy0: 61: Chn 2 pmi=0x01bb810f;pmq=0x01bbfa79;iqcm=0xfffe26bb; Tue Dec 27 22:36:41 2016 kern.debug kernel: [ 112.479262] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.577086] ath: phy0: 62: Chn 0 pmi=0x016b1081;pmq=0x016654ca;iqcm=0x00034dc6; Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.584461] ath: phy0: 62: Chn 1 pmi=0x017da552;pmq=0x015c0920;iqcm=0xfffa1ee3; Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.591833] ath: phy0: 62: Chn 2 pmi=0x01c63645;pmq=0x01c4d422;iqcm=0xfffe74fc; Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.599183] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.697090] ath: phy0: 63: Chn 0 pmi=0x01793ca3;pmq=0x017345f7;iqcm=0x0002a10b; Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.704466] ath: phy0: 63: Chn 1 pmi=0x018a045c;pmq=0x016946f8;iqcm=0xfff9e48c; Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.711841] ath: phy0: 63: Chn 2 pmi=0x01d3a5d5;pmq=0x01d02e62;iqcm=0xfffd969d; Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.719191] ath: phy0: Starting IQ Cal and Correction for Chain 0 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.725315] ath: phy0: Original: Chn 0 iq_corr_meas = 0x0002a10b Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.731363] ath: phy0: Chn 0 pwr_meas_i = 0x01793ca3 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.736346] ath: phy0: Chn 0 pwr_meas_q = 0x017345f7 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.741347] ath: phy0: iqCorrNeg is 0x00000000 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.745811] ath: phy0: Chn 0 iCoff = 0x00000000 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.750378] ath: phy0: Chn 0 qCoff = 0x00000001 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.754927] ath: phy0: New: Chn 0 iCoff = 0x00000000 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.759931] ath: phy0: Chn 0 : iCoff = 0x40 qCoff = 0x1 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.765272] ath: phy0: IQ Cal and Correction done for Chain 0 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.771055] ath: phy0: Starting IQ Cal and Correction for Chain 1 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.777188] ath: phy0: Original: Chn 1 iq_corr_meas = 0xfff9e48c Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.783215] ath: phy0: Chn 1 pwr_meas_i = 0x018a045c Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.788219] ath: phy0: Chn 1 pwr_meas_q = 0x016946f8 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.793201] ath: phy0: iqCorrNeg is 0x00000001 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.797674] ath: phy0: Chn 1 iCoff = 0x00000002 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.802222] ath: phy0: Chn 1 qCoff = 0x00000005 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.806777] ath: phy0: New: Chn 1 iCoff = 0x00000002 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.811780] ath: phy0: Chn 1 : iCoff = 0x2 qCoff = 0x5 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.817039] ath: phy0: IQ Cal and Correction done for Chain 1 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.822805] ath: phy0: Starting IQ Cal and Correction for Chain 2 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.828941] ath: phy0: Original: Chn 2 iq_corr_meas = 0xfffd969d Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.834970] ath: phy0: Chn 2 pwr_meas_i = 0x01d3a5d5 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.839973] ath: phy0: Chn 2 pwr_meas_q = 0x01d02e62 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.844955] ath: phy0: iqCorrNeg is 0x00000001 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.849437] ath: phy0: Chn 2 iCoff = 0x00000000 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.853985] ath: phy0: Chn 2 qCoff = 0x00000000 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.858553] ath: phy0: New: Chn 2 iCoff = 0x00000000 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.863538] ath: phy0: Chn 2 : iCoff = 0x0 qCoff = 0x0 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.868802] ath: phy0: IQ Cal and Correction done for Chain 2 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.874576] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.880183] ath: phy0: NF calibrated [ctl] [chain 1] is -90 Tue Dec 27 22:36:42 2016 kern.debug kernel: [ 112.885785] ath: phy0: NF calibrated [ctl] [chain 2] is -89 Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.517029] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.527947] ath: phy0: Failed to stop TX DMA, queues=0x002! Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.540425] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.546033] ath: phy0: NF calibrated [ctl] [chain 1] is -90 Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.551678] ath: phy0: NF calibrated [ctl] [chain 2] is -89 Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.588036] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.594481] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.598973] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:51 2016 kern.debug kernel: [ 121.604221] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.617023] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.628055] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.633666] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.639323] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.675653] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.682119] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.686582] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:52 2016 kern.debug kernel: [ 122.691855] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.707020] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.716234] ath: phy0: NF calibrated [ctl] [chain 0] is -109 Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.722003] ath: phy0: NF[0] (-109) < MIN (-100), correcting to NOM Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.728311] ath: phy0: NF calibrated [ctl] [chain 1] is -108 Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.733999] ath: phy0: NF[1] (-108) < MIN (-100), correcting to NOM Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.740308] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.776641] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.783109] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.787589] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:53 2016 kern.debug kernel: [ 123.792842] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.797028] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.803197] ath: phy0: NF calibrated [ctl] [chain 0] is -93 Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.808879] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.814473] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.850816] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.857253] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.861715] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:54 2016 kern.debug kernel: [ 124.866969] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.877052] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.883003] ath: phy0: NF calibrated [ctl] [chain 0] is -109 Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.888767] ath: phy0: NF[0] (-109) < MIN (-100), correcting to NOM Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.895069] ath: phy0: NF calibrated [ctl] [chain 1] is -108 Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.900772] ath: phy0: NF[1] (-108) < MIN (-100), correcting to NOM Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.907083] ath: phy0: NF calibrated [ctl] [chain 2] is -89 Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.943417] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.949883] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.954345] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:55 2016 kern.debug kernel: [ 125.959618] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 126.967021] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 126.973556] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 126.979239] ath: phy0: NF calibrated [ctl] [chain 1] is -92 Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 126.984835] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 127.021180] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 127.027624] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 127.032086] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:56 2016 kern.debug kernel: [ 127.037356] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.047028] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.052847] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.058522] ath: phy0: NF calibrated [ctl] [chain 1] is -90 Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.064116] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.100460] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.106898] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.111392] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:57 2016 kern.debug kernel: [ 128.116638] ath: phy0: Setting CFG 0x10a Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.127041] ath: phy0: tx hung, resetting the chip Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.132607] ath: phy0: NF calibrated [ctl] [chain 0] is -93 Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.138272] ath: phy0: NF calibrated [ctl] [chain 1] is -92 Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.143868] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.180211] ath: phy0: ah->misc_mode 0xc Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.186649] ath: phy0: enabling IQ Calibration Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.191143] ath: phy0: starting IQ Mismatch Calibration Tue Dec 27 22:36:58 2016 kern.debug kernel: [ 129.196391] ath: phy0: Setting CFG 0x10a

wifi is gone

Tue Dec 27 22:37:28 2016 kern.debug kernel: [ 159.197039] ath: phy0: 0: Chn 0 pmi=0x00012439;pmq=0x00017528;iqcm=0x0000049c;
Tue Dec 27 22:37:28 2016 kern.debug kernel: [ 159.204318] ath: phy0: 0: Chn 1 pmi=0x0003bf6f;pmq=0x000534c7;iqcm=0x0000499f;
Tue Dec 27 22:37:28 2016 kern.debug kernel: [ 159.211593] ath: phy0: 0: Chn 2 pmi=0x00024e7d;pmq=0x0002af25;iqcm=0xffffe40c;
Tue Dec 27 22:37:28 2016 kern.debug kernel: [ 159.218858] ath: phy0: starting IQ Mismatch Calibration

This is how it looks in the iperf client:

Client connecting to sven-virtualbox, TCP port 5001 TCP window size: 512 KByte (default) ------------------------------------------------------------ [ 3] local 192.168.1.155 port 45565 connected with 192.168.1.223 port 5001 [ ID] Interval Transfer Bandwidth [ 3] 0.0- 1.0 sec 4.25 MBytes 35.7 Mbits/sec [ 3] 1.0- 2.0 sec 3.00 MBytes 25.2 Mbits/sec [ 3] 2.0- 3.0 sec 4.50 MBytes 37.7 Mbits/sec [ 3] 3.0- 4.0 sec 5.00 MBytes 41.9 Mbits/sec [ 3] 4.0- 5.0 sec 4.38 MBytes 36.7 Mbits/sec [ 3] 5.0- 6.0 sec 4.75 MBytes 39.8 Mbits/sec [ 3] 6.0- 7.0 sec 4.75 MBytes 39.8 Mbits/sec [ 3] 7.0- 8.0 sec 3.88 MBytes 32.5 Mbits/sec [ 3] 8.0- 9.0 sec 2.25 MBytes 18.9 Mbits/sec [ 3] 9.0-10.0 sec 0.00 Bytes 0.00 bits/sec [ 3] 10.0-11.0 sec 0.00 Bytes 0.00 bits/sec

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 27, 2016

nbd:

I pushed another fix you can test to my staging tree. It fixes some issues with calibration (which might play a role in these hangs).

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 28, 2016

IronicSven:

Hi Felix,

building from your staging tree fails with:

mkimage -A mips -O linux -T kernel -a 0x80060000 -C lzma -e 0x80060000 -n 'MIPS OpenWrt Linux-4.4.39' -d /home/sven/openwrt/staging/build_dir/target-mips_24kc_musl-1.1.15/linux-ar71xx_generic/vmlinux.bin.lzma /home/sven/openwrt/staging/bin/targets/ar71xx/generic/lede-ar71xx-generic-uImage-lzma.bin mkimage: error while loading shared libraries: libssl.so.39: cannot open shared object file: No such file or directory Makefile:97: recipe for target 'kernel_prepare' failed

But I copied package/kernel/mac80211/patches/347-ath9k-don-t-run-periodic-and-nf-calibation-at-the-sa.patch to the source tree and build.

Wifi still disconnects and disappears:

root@FlensNet:~# cat /etc/os-release | grep BUILD BUILD_ID="r2697-19059d8" root@FlensNet:~# logread -f Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 332.937592] ath: phy0: 25: Chn 0 pmi=0x0116f140;pmq=0x00f32914;iqcm=0xfffbe571; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 332.944984] ath: phy0: 25: Chn 1 pmi=0x01056afb;pmq=0x00e676de;iqcm=0xffed8386; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 332.952353] ath: phy0: 25: Chn 2 pmi=0x012f4ac0;pmq=0x014e9e63;iqcm=0xfffb4073; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 332.959703] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.057560] ath: phy0: 26: Chn 0 pmi=0x011f2bb3;pmq=0x00fd3564;iqcm=0xfffdc475; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.064935] ath: phy0: 26: Chn 1 pmi=0x0112454a;pmq=0x00edba2e;iqcm=0xffeef206; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.072305] ath: phy0: 26: Chn 2 pmi=0x0135cf0b;pmq=0x0153a3c2;iqcm=0xfff9da25; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.079659] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.177571] ath: phy0: 27: Chn 0 pmi=0x012ac42e;pmq=0x010e011e;iqcm=0xfffc3314; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.184949] ath: phy0: 27: Chn 1 pmi=0x012781ff;pmq=0x0104af28;iqcm=0xfff0f89e; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.192316] ath: phy0: 27: Chn 2 pmi=0x014e6c33;pmq=0x016504ef;iqcm=0xfffc548f; Wed Dec 28 19:33:43 2016 kern.debug kernel: [ 333.199668] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.297593] ath: phy0: 28: Chn 0 pmi=0x01355eed;pmq=0x011733fe;iqcm=0xfffdea77; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.304975] ath: phy0: 28: Chn 1 pmi=0x01311926;pmq=0x010a570d;iqcm=0xfff14206; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.312344] ath: phy0: 28: Chn 2 pmi=0x01570f73;pmq=0x016e1511;iqcm=0xfffa5981; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.319694] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.417566] ath: phy0: 29: Chn 0 pmi=0x01402caf;pmq=0x011fcbb1;iqcm=0xfffd02fb; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.424940] ath: phy0: 29: Chn 1 pmi=0x013985c5;pmq=0x01123421;iqcm=0xfff03570; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.432313] ath: phy0: 29: Chn 2 pmi=0x01670d69;pmq=0x018201a0;iqcm=0xfffb32f1; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.439668] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.537551] ath: phy0: 30: Chn 0 pmi=0x0147317b;pmq=0x01282f28;iqcm=0xfffdbff9; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.544928] ath: phy0: 30: Chn 1 pmi=0x01420b08;pmq=0x0119af07;iqcm=0xfff13dde; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.552301] ath: phy0: 30: Chn 2 pmi=0x016c766a;pmq=0x01860125;iqcm=0xfffac293; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.559657] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.657570] ath: phy0: 31: Chn 0 pmi=0x0151bda6;pmq=0x0131d4df;iqcm=0xfffdf6f8; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.664944] ath: phy0: 31: Chn 1 pmi=0x014d18d2;pmq=0x0122d665;iqcm=0xfff153b3; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.672321] ath: phy0: 31: Chn 2 pmi=0x01727185;pmq=0x018bd0f8;iqcm=0xfffa83e7; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.679678] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.777546] ath: phy0: 32: Chn 0 pmi=0x015b2b23;pmq=0x0138ab95;iqcm=0xfffd4a37; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.784923] ath: phy0: 32: Chn 1 pmi=0x0156c208;pmq=0x012cd0a7;iqcm=0xfff05bcd; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.792291] ath: phy0: 32: Chn 2 pmi=0x017c5a64;pmq=0x01989722;iqcm=0xfffb141b; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.799648] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.897546] ath: phy0: 33: Chn 0 pmi=0x0163f2c5;pmq=0x01401afd;iqcm=0xfffbfa15; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.904939] ath: phy0: 33: Chn 1 pmi=0x015ff174;pmq=0x01384d0e;iqcm=0xffeeccf1; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.912308] ath: phy0: 33: Chn 2 pmi=0x018615fe;pmq=0x01a44025;iqcm=0xfffce338; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 333.919665] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.017562] ath: phy0: 34: Chn 0 pmi=0x016da0da;pmq=0x01485903;iqcm=0xfffaa932; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.024937] ath: phy0: 34: Chn 1 pmi=0x016a9902;pmq=0x014422fa;iqcm=0xffed3b55; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.032309] ath: phy0: 34: Chn 2 pmi=0x018f4083;pmq=0x01aef418;iqcm=0xfffe5490; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.039665] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.137539] ath: phy0: 35: Chn 0 pmi=0x017789d5;pmq=0x01514934;iqcm=0xfff97113; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.144911] ath: phy0: 35: Chn 1 pmi=0x0174bf29;pmq=0x014f5d06;iqcm=0xffecbec8; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.152285] ath: phy0: 35: Chn 2 pmi=0x0199f5f6;pmq=0x01ba1def;iqcm=0xffff6a2b; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.159639] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.257717] ath: phy0: 36: Chn 0 pmi=0x01807374;pmq=0x015eb9f7;iqcm=0xfff9bf54; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.265092] ath: phy0: 36: Chn 1 pmi=0x017d81a0;pmq=0x0157f619;iqcm=0xffef1ec2; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.272483] ath: phy0: 36: Chn 2 pmi=0x01a40a6c;pmq=0x01bfab17;iqcm=0xffff53dc; Wed Dec 28 19:33:44 2016 kern.debug kernel: [ 334.279840] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.377564] ath: phy0: 37: Chn 0 pmi=0x018a4ad3;pmq=0x0167fbfd;iqcm=0xfffa49d4; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.384943] ath: phy0: 37: Chn 1 pmi=0x018a9594;pmq=0x01621407;iqcm=0xffef15f8; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.392313] ath: phy0: 37: Chn 2 pmi=0x01ad41bf;pmq=0x01c8be59;iqcm=0xfffe82c3; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.399663] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.497630] ath: phy0: 38: Chn 0 pmi=0x0193464e;pmq=0x0173da21;iqcm=0xfff8e0ac; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.504987] ath: phy0: 38: Chn 1 pmi=0x019008ba;pmq=0x0167d364;iqcm=0xfff02cad; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.512377] ath: phy0: 38: Chn 2 pmi=0x01b6e605;pmq=0x01cee40e;iqcm=0xffff3f9c; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.519735] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.617539] ath: phy0: 39: Chn 0 pmi=0x019dd381;pmq=0x017d221e;iqcm=0xfff8c726; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.624915] ath: phy0: 39: Chn 1 pmi=0x0198d820;pmq=0x016f3fd5;iqcm=0xffefa65a; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.632288] ath: phy0: 39: Chn 2 pmi=0x01bda8bd;pmq=0x01d60409;iqcm=0xffff20ed; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.639644] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.737564] ath: phy0: 40: Chn 0 pmi=0x01a7bde5;pmq=0x01882adf;iqcm=0xfff7defd; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.744926] ath: phy0: 40: Chn 1 pmi=0x01a1cfc6;pmq=0x0178bb60;iqcm=0xfff06da1; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.752298] ath: phy0: 40: Chn 2 pmi=0x01c86ebb;pmq=0x01de27a1;iqcm=0xffffc46f; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.759653] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.857529] ath: phy0: 41: Chn 0 pmi=0x01b102c5;pmq=0x019371f6;iqcm=0xfffa1cc2; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.864907] ath: phy0: 41: Chn 1 pmi=0x01aeb5d0;pmq=0x01804a5e;iqcm=0xfff2aa14; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.872275] ath: phy0: 41: Chn 2 pmi=0x01d3e2df;pmq=0x01e68df5;iqcm=0xfffcfc29; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.879626] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.977619] ath: phy0: 42: Chn 0 pmi=0x01b944cd;pmq=0x019e8ac5;iqcm=0xfff9316a; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.984995] ath: phy0: 42: Chn 1 pmi=0x01b76489;pmq=0x018ab76f;iqcm=0xfff3d927; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.992385] ath: phy0: 42: Chn 2 pmi=0x01dbf56c;pmq=0x01ebf3a0;iqcm=0xfffd734a; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 334.999741] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.097553] ath: phy0: 43: Chn 0 pmi=0x01c34ac3;pmq=0x01aa00be;iqcm=0xfff892f6; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.104934] ath: phy0: 43: Chn 1 pmi=0x01bebc50;pmq=0x0192b661;iqcm=0xfff42338; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.112303] ath: phy0: 43: Chn 2 pmi=0x01e4ec6e;pmq=0x01f30175;iqcm=0xfffdc199; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.119660] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.217513] ath: phy0: 44: Chn 0 pmi=0x01d15b03;pmq=0x01b729b2;iqcm=0xfff46905; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.224883] ath: phy0: 44: Chn 1 pmi=0x01c6f998;pmq=0x01a39d73;iqcm=0xfff35674; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.232253] ath: phy0: 44: Chn 2 pmi=0x01f9d4cf;pmq=0x0208c083;iqcm=0x0005882d; Wed Dec 28 19:33:45 2016 kern.debug kernel: [ 335.239608] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.337523] ath: phy0: 45: Chn 0 pmi=0x01d85c21;pmq=0x01c29fda;iqcm=0xfff5a2b4; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.344897] ath: phy0: 45: Chn 1 pmi=0x01d0cbb4;pmq=0x01ab0a6b;iqcm=0xfff64a70; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.352266] ath: phy0: 45: Chn 2 pmi=0x02021680;pmq=0x020ce1f6;iqcm=0x0004562a; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.359617] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.457530] ath: phy0: 46: Chn 0 pmi=0x01e19df9;pmq=0x01cb5bf6;iqcm=0xfff5aad8; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.464898] ath: phy0: 46: Chn 1 pmi=0x01d93c3b;pmq=0x01b26da1;iqcm=0xfff6177c; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.472272] ath: phy0: 46: Chn 2 pmi=0x020b5e73;pmq=0x02162990;iqcm=0x00043038; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.479624] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.577508] ath: phy0: 47: Chn 0 pmi=0x01f03c7f;pmq=0x01d38382;iqcm=0xfff5181a; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.584884] ath: phy0: 47: Chn 1 pmi=0x01e38332;pmq=0x01bbf95d;iqcm=0xfff301da; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.592258] ath: phy0: 47: Chn 2 pmi=0x0212641e;pmq=0x0222a50f;iqcm=0x0004f55c; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.599615] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.697641] ath: phy0: 48: Chn 0 pmi=0x01fd8e31;pmq=0x01de8504;iqcm=0xfff500cb; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.705000] ath: phy0: 48: Chn 1 pmi=0x01e9d357;pmq=0x01c1670b;iqcm=0xfff2715c; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.712385] ath: phy0: 48: Chn 2 pmi=0x0217ec1e;pmq=0x0228fecf;iqcm=0x0004e370; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.719737] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.817611] ath: phy0: 49: Chn 0 pmi=0x020ad6fd;pmq=0x01ee992a;iqcm=0xfff3274d; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.824979] ath: phy0: 49: Chn 1 pmi=0x01f011b3;pmq=0x01c75f1a;iqcm=0xfff35da0; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.832372] ath: phy0: 49: Chn 2 pmi=0x021f9e68;pmq=0x022e9ab8;iqcm=0x00058169; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.839728] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.937498] ath: phy0: 50: Chn 0 pmi=0x0215889d;pmq=0x01fda9ca;iqcm=0xfff51152; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.944874] ath: phy0: 50: Chn 1 pmi=0x01f5d92e;pmq=0x01ca71e5;iqcm=0xfff2f8ec; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.952250] ath: phy0: 50: Chn 2 pmi=0x0234b32d;pmq=0x023b9a8b;iqcm=0x000342d8; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 335.959604] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.057495] ath: phy0: 51: Chn 0 pmi=0x0220a63b;pmq=0x02059ff2;iqcm=0xfff3e155; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.064869] ath: phy0: 51: Chn 1 pmi=0x01fe988c;pmq=0x01d44f5a;iqcm=0xfff41ca4; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.072239] ath: phy0: 51: Chn 2 pmi=0x023da714;pmq=0x0247ca67;iqcm=0x0003f6ad; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.079595] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.177562] ath: phy0: 52: Chn 0 pmi=0x022a0eee;pmq=0x0211638e;iqcm=0xfff3e75c; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.184935] ath: phy0: 52: Chn 1 pmi=0x020c0962;pmq=0x01ddd569;iqcm=0xfff2c3ab; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.192317] ath: phy0: 52: Chn 2 pmi=0x02483de0;pmq=0x024f7b57;iqcm=0x00040ea8; Wed Dec 28 19:33:46 2016 kern.debug kernel: [ 336.199674] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.297503] ath: phy0: 53: Chn 0 pmi=0x02336c3b;pmq=0x0218dc3f;iqcm=0xfff3c0e1; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.304886] ath: phy0: 53: Chn 1 pmi=0x021a3d08;pmq=0x01eb0560;iqcm=0xfff389c0; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.312253] ath: phy0: 53: Chn 2 pmi=0x025276a9;pmq=0x025bceca;iqcm=0x0003d898; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.319603] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.417564] ath: phy0: 54: Chn 0 pmi=0x0243e28d;pmq=0x022c6b19;iqcm=0xfff42088; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.424936] ath: phy0: 54: Chn 1 pmi=0x02248379;pmq=0x01f3a18c;iqcm=0xfff22cae; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.432320] ath: phy0: 54: Chn 2 pmi=0x02635a56;pmq=0x02683507;iqcm=0x0003abf0; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.439674] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.537515] ath: phy0: 55: Chn 0 pmi=0x0251f5a4;pmq=0x023a574a;iqcm=0xfff6b414; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.544892] ath: phy0: 55: Chn 1 pmi=0x022d9c06;pmq=0x01ff1ddc;iqcm=0xfff12df4; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.552261] ath: phy0: 55: Chn 2 pmi=0x02713c07;pmq=0x0275e19f;iqcm=0x0000c3fc; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.559611] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.657481] ath: phy0: 56: Chn 0 pmi=0x025f7d7e;pmq=0x0245c662;iqcm=0xfff64bb1; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.664854] ath: phy0: 56: Chn 1 pmi=0x02398bea;pmq=0x02099301;iqcm=0xfff1b39d; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.672228] ath: phy0: 56: Chn 2 pmi=0x027c097d;pmq=0x0281ddfa;iqcm=0x00013fed; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.679585] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.777486] ath: phy0: 57: Chn 0 pmi=0x026c5069;pmq=0x0254530c;iqcm=0xfff992b3; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.784862] ath: phy0: 57: Chn 1 pmi=0x0243c684;pmq=0x02179456;iqcm=0xffefc684; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.792237] ath: phy0: 57: Chn 2 pmi=0x02895b30;pmq=0x028c13a3;iqcm=0xfffe6330; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.799593] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.897493] ath: phy0: 58: Chn 0 pmi=0x027dde59;pmq=0x025c8b6a;iqcm=0xfffb1364; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.904869] ath: phy0: 58: Chn 1 pmi=0x024d5634;pmq=0x0225f9a1;iqcm=0xfff29be3; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.912240] ath: phy0: 58: Chn 2 pmi=0x029a8cf6;pmq=0x02a0110d;iqcm=0xfff8ae9e; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 336.919593] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.017480] ath: phy0: 59: Chn 0 pmi=0x028b3819;pmq=0x02662e62;iqcm=0xfffe5568; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.024853] ath: phy0: 59: Chn 1 pmi=0x025604ac;pmq=0x02352338;iqcm=0xfff24c83; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.032228] ath: phy0: 59: Chn 2 pmi=0x02a5ddba;pmq=0x02abe70b;iqcm=0xfff52164; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.039584] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.137484] ath: phy0: 60: Chn 0 pmi=0x029720ee;pmq=0x02775499;iqcm=0xffffa522; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.144864] ath: phy0: 60: Chn 1 pmi=0x02699f8d;pmq=0x0243e5a8;iqcm=0xffee440a; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.152232] ath: phy0: 60: Chn 2 pmi=0x02b1d96d;pmq=0x02b3c431;iqcm=0xfff4a65d; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.159583] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.257505] ath: phy0: 61: Chn 0 pmi=0x02a0b78d;pmq=0x028266d6;iqcm=0xffff209f; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.264879] ath: phy0: 61: Chn 1 pmi=0x0274b078;pmq=0x024c2c48;iqcm=0xffed96d5; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.272251] ath: phy0: 61: Chn 2 pmi=0x02bd3cef;pmq=0x02bcbb86;iqcm=0xfff53806; Wed Dec 28 19:33:47 2016 kern.debug kernel: [ 337.279599] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.377586] ath: phy0: 62: Chn 0 pmi=0x02ac5ea5;pmq=0x028c20f6;iqcm=0xfffe252e; Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.384951] ath: phy0: 62: Chn 1 pmi=0x027dc97e;pmq=0x025384ed;iqcm=0xffee3c20; Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.392341] ath: phy0: 62: Chn 2 pmi=0x02c7607d;pmq=0x02c7a4b5;iqcm=0xfff654c6; Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.399697] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.497488] ath: phy0: 63: Chn 0 pmi=0x02ba601b;pmq=0x0299f561;iqcm=0xfffe0184; Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.504854] ath: phy0: 63: Chn 1 pmi=0x0290c94c;pmq=0x0263df4c;iqcm=0xffedb708; Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.512229] ath: phy0: 63: Chn 2 pmi=0x02d159f2;pmq=0x02d015d1;iqcm=0xfff634ef; Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.519584] ath: phy0: Starting IQ Cal and Correction for Chain 0 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.525706] ath: phy0: Original: Chn 0 iq_corr_meas = 0xfffe0184 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.531756] ath: phy0: Chn 0 pwr_meas_i = 0x02ba601b Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.536746] ath: phy0: Chn 0 pwr_meas_q = 0x0299f561 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.541749] ath: phy0: iqCorrNeg is 0x00000001 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.546210] ath: phy0: Chn 0 iCoff = 0x00000000 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.550779] ath: phy0: Chn 0 qCoff = 0x00000003 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.555326] ath: phy0: New: Chn 0 iCoff = 0x00000000 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.560332] ath: phy0: Chn 0 : iCoff = 0x0 qCoff = 0x3 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.565585] ath: phy0: IQ Cal and Correction done for Chain 0 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.571371] ath: phy0: Starting IQ Cal and Correction for Chain 1 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.577503] ath: phy0: Original: Chn 1 iq_corr_meas = 0xffedb708 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.583538] ath: phy0: Chn 1 pwr_meas_i = 0x0290c94c Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.588542] ath: phy0: Chn 1 pwr_meas_q = 0x0263df4c Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.593531] ath: phy0: iqCorrNeg is 0x00000001 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.598006] ath: phy0: Chn 1 iCoff = 0x00000003 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.602561] ath: phy0: Chn 1 qCoff = 0x00000004 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.607116] ath: phy0: New: Chn 1 iCoff = 0x00000003 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.612124] ath: phy0: Chn 1 : iCoff = 0x3 qCoff = 0x4 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.617373] ath: phy0: IQ Cal and Correction done for Chain 1 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.623169] ath: phy0: Starting IQ Cal and Correction for Chain 2 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.629309] ath: phy0: Original: Chn 2 iq_corr_meas = 0xfff634ef Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.635344] ath: phy0: Chn 2 pwr_meas_i = 0x02d159f2 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.640349] ath: phy0: Chn 2 pwr_meas_q = 0x02d015d1 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.645338] ath: phy0: iqCorrNeg is 0x00000001 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.649821] ath: phy0: Chn 2 iCoff = 0x00000001 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.654376] ath: phy0: Chn 2 qCoff = 0x00000000 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.658946] ath: phy0: New: Chn 2 iCoff = 0x00000001 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.663939] ath: phy0: Chn 2 : iCoff = 0x1 qCoff = 0x0 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.669203] ath: phy0: IQ Cal and Correction done for Chain 2 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.767480] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.773093] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Wed Dec 28 19:33:48 2016 kern.debug kernel: [ 337.778717] ath: phy0: NF calibrated [ctl] [chain 2] is -89 Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.757307] ath: phy0: tx hung, resetting the chip Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.769086] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.774701] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.780342] ath: phy0: NF calibrated [ctl] [chain 2] is -89 Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.816668] ath: phy0: ah->misc_mode 0xc Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.823137] ath: phy0: enabling IQ Calibration Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.827618] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:58 2016 kern.debug kernel: [ 347.832870] ath: phy0: Setting CFG 0x10a Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.837255] ath: phy0: tx hung, resetting the chip Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.848300] ath: phy0: NF calibrated [ctl] [chain 0] is -93 Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.853913] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.859569] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.895898] ath: phy0: ah->misc_mode 0xc Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.902366] ath: phy0: enabling IQ Calibration Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.906829] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:33:59 2016 kern.debug kernel: [ 348.912103] ath: phy0: Setting CFG 0x10a Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.927241] ath: phy0: tx hung, resetting the chip Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.934038] ath: phy0: NF calibrated [ctl] [chain 0] is -93 Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.939727] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.945337] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.981677] ath: phy0: ah->misc_mode 0xc Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.988118] ath: phy0: enabling IQ Calibration Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.992580] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:34:00 2016 kern.debug kernel: [ 349.997851] ath: phy0: Setting CFG 0x10a Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.007247] ath: phy0: tx hung, resetting the chip Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.013115] ath: phy0: NF calibrated [ctl] [chain 0] is -92 Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.018798] ath: phy0: NF calibrated [ctl] [chain 1] is -91 Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.024393] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.060733] ath: phy0: ah->misc_mode 0xc Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.067174] ath: phy0: enabling IQ Calibration Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.071669] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:34:01 2016 kern.debug kernel: [ 351.076925] ath: phy0: Setting CFG 0x10a Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.087210] ath: phy0: tx hung, resetting the chip Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.093158] ath: phy0: NF calibrated [ctl] [chain 0] is -93 Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.098827] ath: phy0: NF calibrated [ctl] [chain 1] is -92 Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.104424] ath: phy0: NF calibrated [ctl] [chain 2] is -90 Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.140764] ath: phy0: ah->misc_mode 0xc Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.147225] ath: phy0: enabling IQ Calibration Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.151693] ath: phy0: starting IQ Mismatch Calibration Wed Dec 28 19:34:02 2016 kern.debug kernel: [ 352.156947] ath: phy0: Setting CFG 0x10a

wifi is gone

Wed Dec 28 19:34:32 2016 kern.debug kernel: [ 382.156821] ath: phy0: 0: Chn 0 pmi=0x000b728f;pmq=0x000a0cbc;iqcm=0xffff9285;
Wed Dec 28 19:34:32 2016 kern.debug kernel: [ 382.164094] ath: phy0: 0: Chn 1 pmi=0x000aebea;pmq=0x000966be;iqcm=0x00004c6e;
Wed Dec 28 19:34:32 2016 kern.debug kernel: [ 382.171375] ath: phy0: 0: Chn 2 pmi=0x0009e251;pmq=0x000aeefd;iqcm=0xffffc9ed;
Wed Dec 28 19:34:32 2016 kern.debug kernel: [ 382.178638] ath: phy0: starting IQ Mismatch Calibration

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 29, 2016

amain:

Hi Felix,

Thanks for the patch, but it does not seem to work. I compiled an image using your staging area, up to commit 2782d36a4053b9879ea84b9e29c347eb4471c639, and the problem is still there.

ath9k debug level:

echo 0x00000409 > /sys/kernel/debug/ieee80211/phy0/ath9k/debug

iperf:

...
2016-12-29 11:34:49 [ 4] 286.5-287.0 sec 1.41 MBytes 23.7 Mbits/sec
2016-12-29 11:34:50 [ 4] 287.0-287.5 sec 1.21 MBytes 20.3 Mbits/sec
2016-12-29 11:34:50 [ 4] 287.5-288.0 sec 1.19 MBytes 19.9 Mbits/sec
2016-12-29 11:34:51 [ 4] 288.0-288.5 sec 1.34 MBytes 22.4 Mbits/sec
(connection lost)

router log:

..
Dec 29 11:33:22 debwrt kernel: [ 1383.295518] ath: phy0: NF calibrated [ctl] [chain 0] is -89
Dec 29 11:33:22 debwrt kernel: [ 1383.295555] ath: phy0: NF calibrated [ctl] [chain 1] is -88
Dec 29 11:33:22 debwrt kernel: [ 1383.295576] ath: phy0: NF calibrated [ctl] [chain 2] is -87
Dec 29 11:33:52 debwrt kernel: [ 1413.559811] ath: phy0: NF calibrated [ctl] [chain 0] is -88
Dec 29 11:33:52 debwrt kernel: [ 1413.559847] ath: phy0: NF calibrated [ctl] [chain 1] is -88
Dec 29 11:33:52 debwrt kernel: [ 1413.559869] ath: phy0: NF calibrated [ctl] [chain 2] is -87
Dec 29 11:34:22 debwrt kernel: [ 1443.626346] ath: phy0: NF calibrated [ctl] [chain 0] is -88
Dec 29 11:34:22 debwrt kernel: [ 1443.626382] ath: phy0: NF calibrated [ctl] [chain 1] is -89
Dec 29 11:34:22 debwrt kernel: [ 1443.626404] ath: phy0: NF calibrated [ctl] [chain 2] is -88
Dec 29 11:34:52 debwrt kernel: [ 1473.699523] ath: phy0: NF calibrated [ctl] [chain 0] is -89
Dec 29 11:34:52 debwrt kernel: [ 1473.699558] ath: phy0: NF calibrated [ctl] [chain 1] is -89
Dec 29 11:34:52 debwrt kernel: [ 1473.699580] ath: phy0: NF calibrated [ctl] [chain 2] is -89
Dec 29 11:34:52 debwrt kernel: [ 1473.799518] ath: phy0: tx hung, resetting the chip
Dec 29 11:34:52 debwrt kernel: [ 1473.830307] ath: phy0: NF calibrated [ctl] [chain 0] is -89
Dec 29 11:34:52 debwrt kernel: [ 1473.830340] ath: phy0: NF calibrated [ctl] [chain 1] is -89
Dec 29 11:34:52 debwrt kernel: [ 1473.830362] ath: phy0: NF calibrated [ctl] [chain 2] is -89
Dec 29 11:34:52 debwrt kernel: [ 1473.861072] ath: phy0: ah->misc_mode 0xc
Dec 29 11:34:52 debwrt kernel: [ 1473.863588] ath: phy0: enabling IQ Calibration
Dec 29 11:34:52 debwrt kernel: [ 1473.863608] ath: phy0: starting IQ Mismatch Calibration
Dec 29 11:34:52 debwrt kernel: [ 1473.863631] ath: phy0: Setting CFG 0x10a
...

After the connections gets lost, the log starts to show the "resetting the chip" message about every second for a while. See attached a larger syslog.

If there is anything a can do to help to debug or test, please let me know.

A way to get past the compile error already reported by Sven:

$ # revert commit: https://git.lede-project.org/?p=source.git;a=commit;h=2fd5ce9488d11c7e6eee7dc30f128bd12be889f5
$ make tools/libressl/clean
$ make tools/libressl/install
$ export LD_LIBRARY_PATH=$(readlink -f build_dir/host/libressl-2.5.0/ssl/.libs):$(readlink -f build_dir/host/libressl-2.5.0/crypto/.libs)
$ make -j4

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Dec 31, 2016

IronicSven:

Hi Felix,

I've spend some time today to understand tiny parts of the ath9k code and got better debugging results with this debugging level:

root@FlensNet:~# echo 0x00266665 > /sys/kernel/debug/ieee80211/phy0/ath9k/debug

It shows that there are recurring beacon problems before multiple calibrations and the tx hung:

... Sat Dec 31 18:07:32 2016 kern.debug kernel: [ 1187.102795] ath: phy0: resume beacon xmit after 1 misses Sat Dec 31 18:07:32 2016 kern.debug kernel: [ 1187.115571] ath: phy0: missed 1 consecutive beacons ...

The missing beacons might be the root cause.

You can find the complete syslog here: http://pastebin.com/8rcr3Gq1

PS: Building from your staging tree works now for me.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 1, 2017

mgondium:

LEDE Reboot SNAPSHOT r2726-0e947112bf from nbd's staging, TPLINK 1043ND v1

radio no longer "disappears" but clients drop constantly.

echo 0xffffffff >/sys/kernel/debug/ieee80211/phy0/ath9k/debug
logs non-stop for slots 0-7:
(...)
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.158229] ath: phy0: slot: 0 tsf: 117760017 tsftu: 115000
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.163860] ath: phy0: disable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.167330] ath: phy0: resume beacon xmit after 1 misses
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.172670] ath: phy0: Transmitting beacon for slot: 0
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.177867] ath: phy0: Enable TXE on queue: 9
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.182900] ath: phy0: enable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.186302] ath: phy0: AR_IMR 0x918104b0 IER 0x1
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.190955] ath: phy0: disable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.195022] ath: phy0: enable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.198374] ath: phy0: AR_IMR 0x918104b0 IER 0x1
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.217797] ath: phy0: disable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.221343] ath: phy0: enable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.224725] ath: phy0: disable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.228152] ath: phy0: AR_IMR 0x918104b0 IER 0x0
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.233299] ath: phy0: enable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.236658] ath: phy0: disable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.240090] ath: phy0: AR_IMR 0x918104b0 IER 0x0
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.245519] ath: phy0: enable IER
Sun Jan 1 22:10:15 2017 kern.debug kernel: [ 191.248871] ath: phy0: AR_IMR 0x918104b0 IER 0x1
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.265562] ath: phy0: disable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.269079] ath: phy0: enable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.272422] ath: phy0: AR_IMR 0x918104b0 IER 0x1
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.286231] ath: phy0: missed 1 consecutive beacons
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.320187] ath: phy0: disable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.323758] ath: phy0: enable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.327109] ath: phy0: disable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.330543] ath: phy0: AR_IMR 0x918104b0 IER 0x0
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.335976] ath: phy0: enable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.339342] ath: phy0: disable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.342780] ath: phy0: AR_IMR 0x918104b0 IER 0x0
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.348027] ath: phy0: enable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.351374] ath: phy0: AR_IMR 0x918104b0 IER 0x1
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.367895] ath: phy0: disable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.371417] ath: phy0: enable IER
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.374792] ath: phy0: AR_IMR 0x918104b0 IER 0x1
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.393232] ath: phy0: listenTime=1222 OFDM:3 errs=96/s CCK:2 errs=120/s ofdm_turn=1
Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.401046] ath: phy0: Calibration @4294956434 finished: ani, caldone: true
(...)

other messages include:

Sun Jan 1 22:10:16 2017 kern.debug kernel: [ 191.528526] ath: phy0: Error: rs_phyer=0x1f not a radar error
Sun Jan 1 22:10:18 2017 kern.debug kernel: [ 193.334231] ath: phy0: missed 1 consecutive beacons
Sun Jan 1 22:10:18 2017 kern.debug kernel: [ 193.626947] ath: phy0: **** ccklevel 2=>1, rssi=0[lo=7 hi=40]
Sun Jan 1 22:10:19 2017 kern.debug kernel: [ 194.244704] ath: phy0: Transmitting beacon for slot: 0
Sun Jan 1 22:10:19 2017 kern.debug kernel: [ 194.249871] ath: phy0: Enable TXE on queue: 9
Sun Jan 1 22:10:19 2017 kern.debug kernel: [ 194.358231] ath: phy0: missed 1 consecutive beacons
Sun Jan 1 22:10:19 2017 kern.debug kernel: [ 194.500038] ath: phy0: Error: rs_phyer=0x1f not a radar error
Sun Jan 1 22:10:22 2017 kern.debug kernel: [ 197.587975] ath: phy0: listenTime=452 OFDM:3 errs=70/s CCK:3 errs=285/s ofdm_turn=1
Sun Jan 1 22:10:22 2017 kern.debug kernel: [ 197.595745] ath: phy0: **** ccklevel 3=>4, rssi=0[lo=7 hi=40]
Sun Jan 1 22:10:22 2017 kern.debug kernel: [ 197.601537] ath: phy0: ** ch 2442: level 3=>4[def:2] firstep[level]=8 ini=2
Sun Jan 1 22:10:22 2017 kern.debug kernel: [ 197.608566] ath: phy0: ** ch 2442: level 3=>4[def:2] firstep_low[level]=8 ini=6
Sun Jan 1 22:10:22 2017 kern.debug kernel: [ 197.615936] ath: phy0: ANI parameters: SI=3, ofdmWS=on FS=4 MRCcck=off listenTime=452 ofdmErrs=32 cckErrs=129

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 2, 2017

IronicSven:

Hi pmgp,

I couldn't reproduce the disappearing with the debug level 0xffffffff either. The debug level 0xffffffff slows down the wifi dramatically to ~1mbit and the problem is only reproducable at 30-40mbit.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 2, 2017

mgondium:

Hi Sven,
the drops are probably caused by the missing beacons like you said.
Felix said he was tinkering with the calibration. It looks like it can't converge to a stop, and that's thrashing the cpu or the queues.

Out of curiosity, debug level 0xffffffff on Chaos Calmer is quite mild on the log, producing almost no output:

Sun Jan 1 22:01:11 2017 kern.debug kernel: [ 1063.800000] ath: phy0: Transmitting beacon for slot: 0
Sun Jan 1 22:01:11 2017 kern.debug kernel: [ 1064.050000] ath: phy0: slot: 2 tsf: 236800027 tsftu: 231250
Sun Jan 1 22:01:11 2017 kern.debug kernel: [ 1064.180000] ath: phy0: slot: 3 tsf: 236928023 tsftu: 231375
Sun Jan 1 22:01:12 2017 kern.debug kernel: [ 1064.310000] ath: phy0: slot: 4 tsf: 237056023 tsftu: 231500
Sun Jan 1 22:01:12 2017 kern.debug kernel: [ 1064.430000] ath: phy0: slot: 5 tsf: 237184022 tsftu: 231625
Sun Jan 1 22:01:12 2017 kern.debug kernel: [ 1064.560000] ath: phy0: slot: 6 tsf: 237312024 tsftu: 231750
Sun Jan 1 22:01:12 2017 kern.debug kernel: [ 1064.690000] ath: phy0: slot: 7 tsf: 237440027 tsftu: 23187
5

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 4, 2017

mjw99:

Just a "Me too". I am seeing this with a NETGEAR WNR2000v1 on r2449-7c47f43; it takes around a day for it to manifest.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 13, 2017

bittorf:

can you please all test again after r2695 / c9c68c7

maybe this ticket is related: https://bugs.lede-project.org/index.php?do=details&task_id=373

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 13, 2017

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 13, 2017

IronicSven:

Just tested r2942-27fbf54 on my TP-Link 1043nd v1. Wifi still disconnects and disappears.

Full log from wifi up to tx hung: http://pastebin.com/kYC9s9N3

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 18, 2017

mgondium:

Ditto for staging r3010.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 25, 2017

nbd:

Should be fixed in the latest version, please test

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 25, 2017

IronicSven:

Hi Felix,

I can't reproduce the tx hung and disappearing wifi anymore. Thank you!

However there are still many debugging messages about calibrations and missing beacons. Are those expected?

Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.737341] ath: phy0: resume beacon xmit after 1 misses Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.750043] ath: phy0: missed 1 consecutive beacons Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.839669] ath: phy0: resume beacon xmit after 1 misses Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.852443] ath: phy0: missed 1 consecutive beacons Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.942069] ath: phy0: resume beacon xmit after 1 misses Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.947527] ath: phy0: listenTime=630 OFDM:3 errs=198/s CCK:2 errs=14/s ofdm_turn=1 Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.955251] ath: phy0: **** ofdmlevel 3=>2, rssi=0[lo=7 hi=40] Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 425.961119] ath: phy0: Calibration @12594 finished: ani, caldone: true Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 426.263045] ath: phy0: listenTime=62 OFDM:3 errs=145/s CCK:2 errs=0/s ofdm_turn=0 Wed Jan 25 17:55:08 2017 kern.debug kernel: [ 426.270594] ath: phy0: Calibration @12625 finished: ani, caldone: true

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 25, 2017

nbd:

Should be fine, as long as connectivity to clients is still okay

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 26, 2017

mgondium:

r3144-a40f3f90d6 is looking good.

Thank you, Felix!

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 27, 2017

mgondium:

r3157-2ef3810f9e

Sadly, some of the APs on my TPLINK test farm began disappearing.
Curiously, none of the 1043NDv1 (AR9132) ones did, but most of the 841Nv9 (QCA9533-AL3A)s are gone.

After about 12 hours uptime there is a
"daemon.info hostapd: wlan0: STA [REDACTED MAC] IEEE 802.11: deauthenticated due to local deauth request"
for every client and the AP goes missing.

I believe there is an old bug related to the "local deauth", so I cant't say if it still the "deaf" bug, specially
because the 1043NDs are still going strong and they were the first to go down before the fix.
Anyway, on CC, both models are solid.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 27, 2017

nbd:

Sorry about that, apparently in that patch I forgot to delete a few more lines of code. Should be fixed in current master, please test.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 28, 2017

amain:

Thanks for the patches. But I don't think we're just there yet. I downloaded and tested snapshot r3189-12db207. Bidirectional iperf test shows stable throughput (40 mbit/s each direction), but after a while the kernel crashes. This is reproducible. Serial console output:

[ 1294.022551] ------------[ cut here ]------------
[ 1294.027247] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:306 dev_watchdog+0x1dc/0x260()
[ 1294.035754] NETDEV WATCHDOG: eth0 (ag71xx): transmit queue 0 timed out
[ 1294.042319] Modules linked in: ath9k ath9k_common pppoe ppp_async ath9k_hw ath pppox ppp_generic nf_conntrack_ipv6 mac80211 iptable_nn
[ 1294.106287] CPU: 0 PID: 0 Comm: swapper Not tainted 4.4.45 #0
[ 1294.112066] Stack : 803e4844 00000000 00000001 80440000 8042f1dc 8042ee63 803c5e64 00000000
804a378c 8042d4fc 00000200 00100000 0000000a 800a7618 803cb554 80430000
00000003 8042d4fc 803c9960 81809e34 0000000a 800a5594 00000006 00000000
00000000 801f5400 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
...
[ 1294.148122] Call Trace:
[ 1294.150617] [<800a7618>] vprintk_default+0x24/0x30
[ 1294.155474] [<800a5594>] printk+0x2c/0x38
[ 1294.159515] [<801f5400>] wait_for_xmitr+0x84/0xcc
[ 1294.164289] [<80081c3c>] warn_slowpath_common+0xa0/0xd0
[ 1294.169564] [<801a72dc>] dump_stack+0x14/0x28
[ 1294.173975] [<80071eb0>] show_stack+0x50/0x84
[ 1294.178376] [<80081c3c>] warn_slowpath_common+0xa0/0xd0
[ 1294.183661] [<8028ef3c>] dev_watchdog+0x1dc/0x260
[ 1294.188408] [<80081c98>] warn_slowpath_fmt+0x2c/0x38
[ 1294.193450] [<8028ef3c>] dev_watchdog+0x1dc/0x260
[ 1294.198191] [<8028ed60>] dev_watchdog+0x0/0x260
[ 1294.202782] [<800b08d0>] call_timer_fn.isra.5+0x24/0x80
[ 1294.208051] [<800b0b54>] run_timer_softirq+0x1b4/0x1fc
[ 1294.213248] [<800a89f0>] handle_irq_event_percpu+0x154/0x188
[ 1294.218960] [<800841b8>] __do_softirq+0x250/0x298
[ 1294.223721] [<800abdac>] handle_percpu_irq+0x50/0x80
[ 1294.228746] [<8006a9e0>] plat_irq_dispatch+0xd4/0x10c
[ 1294.233848] [<80060bf4>] handle_int+0x134/0x140
[ 1294.238400]
[ 1294.239904] ---[ end trace 17bad011a41ccba7 ]---
[ 1294.244567] eth0: tx timeout
[ 1299.022570] eth0: tx timeout
[ 1304.022581] eth0: tx timeout
[ 1309.022588] eth0: tx timeout

And from there on the eth0: tx timeout line is repeated every 5 seconds. The fixes seem to have improved things a bit. But maybe the actual problem wasn't fixed and surfaces now in a different part? Or this is a new issue? Laptop still shows it is connected to the wifi, so the situation still seems to reflect current bug description.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 28, 2017

IronicSven:

I've tested b94177e on my TL-WR1043ND v1 with iperf for 30 minutes and had no problems. Maybe the kernel crashes are related to one of the more recent changes or they are device specific. Which device are you using, Johan?

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 28, 2017

amain:

I'm using the TP-Link WR1043ND v1, with it's default NAT setup and wireless N enabled. Using an extra DNAT rule to allow the incoming iperf connection to get forwarded properly as well.

Latest fixes included note changes to some ath9k IRQ handling. And now the eth0 transmit fails with a time-out. Totally not an expert, but could that be related?

@felix, I can open another bug if needed.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 28, 2017

IronicSven:

I just tested a selfbuilt of r3192-5a164dd and it still seems to work for me.

How long does it take for you to reproduce the kernel crash? I tried tests of 20 minutes each in both directions.

My setup:

Galaxy S3 (iperf client) > TL-WR1043ND v1 > LAN connected PC (iperf server)
and
LAN connected PC (iperf client) > TL-WR1043ND v1 > Galaxy S3 (iperf server)

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 28, 2017

nbd:

I don't think the eth0 issues are related at all, they should have a separate ticket. Please check if one exists already before you open up a new one.

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 28, 2017

amain:

Created follow up bug FS#441 - Kernel crash: eth0 (ag71xx): transmit queue 0 timed out

@sven: In about 20 minutes the kernel crashes. Did you run the iperf tests simultaneously? Can you reply on the new bug?

@openwrt-bot
Copy link
Author

@openwrt-bot openwrt-bot commented Jan 31, 2017

mjw99:

I am no longer seeing this on a NETGEAR WNR2000v1 with 17.01-SNAPSHOT, r3045-e038c60. Many thanks for all your work & efforts here Felix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant