All of lore.kernel.org
 help / color / mirror / Atom feed
* BCM43602 firmware reports multiple BRCMF_E_DEAUTH
@ 2015-09-28  9:00 Rafał Miłecki
  2016-10-04 18:15 ` Rafał Miłecki
  0 siblings, 1 reply; 9+ messages in thread
From: Rafał Miłecki @ 2015-09-28  9:00 UTC (permalink / raw)
  To: linux-wireless, brcm80211 development

[-- Attachment #1: Type: text/plain, Size: 686 bytes --]

Hi,

I'm using recent brcmfmac and brcmfmac43602-pcie.ap.bin that currently
sits in linux-firmware.git.

In OpenWrt we have hostapd with a feature of banning STAs. It works in
a quite simple way. Whenever hostapd gets NL80211_CMD_NEW_STATION for
STA that is banned it sends NL80211_CMD_DEL_STATION.

The problem is that in such case BCM43602 firmware happens to randomly
send more than 1 BRCMF_E_DEAUTH event. It seems it can send random
amount between 1 and 3. Looks a bit like some kind of race. It's
nothing really critical, just makes hostapd log a bit confusing.

Could someone at Broadcom look at firmware source to see if you can
fix this, please?

-- 
Rafał

[-- Attachment #2: syslog-brcmfmac-hostapd.txt --]
[-- Type: text/plain, Size: 1115 bytes --]

Sun Sep 27 19:15:22 2015 kern.info kernel: [ 1047.886433] brcmfmac: [brcmf_notify_connect_status_ap] event:8:BRCMF_E_ASSOC_IND e->addr:78:d6:f0:9b:aa:bb
Sun Sep 27 19:15:22 2015 daemon.info hostapd: wlan0: STA 78:d6:f0:9b:aa:bb IEEE 802.11: associated
Sun Sep 27 19:15:22 2015 daemon.info hostapd: Station 78:d6:f0:9b:aa:bb assoc rejected by ubus handler.

Sun Sep 27 19:15:22 2015 kern.info kernel: [ 1047.897751] brcmfmac: [brcmf_notify_connect_status_ap] event:5:BRCMF_E_DEAUTH e->addr:78:d6:f0:9b:aa:bb
Sun Sep 27 19:15:22 2015 daemon.info hostapd: wlan0: STA 78:d6:f0:9b:aa:bb IEEE 802.11: disassociated

Sun Sep 27 19:15:22 2015 kern.info kernel: [ 1047.908085] brcmfmac: [brcmf_notify_connect_status_ap] event:5:BRCMF_E_DEAUTH e->addr:78:d6:f0:9b:aa:bb
Sun Sep 27 19:15:22 2015 daemon.info hostapd: wlan0: STA 78:d6:f0:9b:aa:bb IEEE 802.11: disassociated

Sun Sep 27 19:15:22 2015 kern.info kernel: [ 1048.414031] brcmfmac: [brcmf_notify_connect_status_ap] event:5:BRCMF_E_DEAUTH e->addr:78:d6:f0:9b:aa:bb
Sun Sep 27 19:15:22 2015 daemon.info hostapd: wlan0: STA 78:d6:f0:9b:aa:bb IEEE 802.11: disassociated

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2015-09-28  9:00 BCM43602 firmware reports multiple BRCMF_E_DEAUTH Rafał Miłecki
@ 2016-10-04 18:15 ` Rafał Miłecki
  2016-10-05  9:08   ` Arend Van Spriel
  2016-10-19 12:34   ` Rafał Miłecki
  0 siblings, 2 replies; 9+ messages in thread
From: Rafał Miłecki @ 2016-10-04 18:15 UTC (permalink / raw)
  To: linux-wireless, brcm80211 development

On 09/28/2015 11:00 AM, Rafał Miłecki wrote:
> I'm using recent brcmfmac and brcmfmac43602-pcie.ap.bin that currently
> sits in linux-firmware.git.
>
> In OpenWrt we have hostapd with a feature of banning STAs. It works in
> a quite simple way. Whenever hostapd gets NL80211_CMD_NEW_STATION for
> STA that is banned it sends NL80211_CMD_DEL_STATION.
>
> The problem is that in such case BCM43602 firmware happens to randomly
> send more than 1 BRCMF_E_DEAUTH event. It seems it can send random
> amount between 1 and 3. Looks a bit like some kind of race. It's
> nothing really critical, just makes hostapd log a bit confusing.
>
> Could someone at Broadcom look at firmware source to see if you can
> fix this, please?

Hey, I didn't get any reply on this for a year. I just saw similar problem with
BCM4366. Below you will find a nice log with my extra comments.

Could take a look at this issue this time, please?

I think it may be another problem related to the A-MPDU thing (bug?) I reported
in "AMPDU stalls with brcmfmac4366b-pcie.bin triggering WARNINGs" e-mail thread.

# My smartphone remains in the same place (1 m from the AP) but there is some
# connection/A-MPDU problem.
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509120] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: wl0.0 scb:0035ee78 tid:0
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509250] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: wl0.0 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509304] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 110486
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509346] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509411] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: txall 4 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509477] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 4 0 0 0 0 ifs_boff 0
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509527] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509576] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509665] brcmfmac: CONSOLE: 026970.308 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509726] brcmfmac: CONSOLE: 026970.308 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Tue Oct  4 17:22:41 2016 kern.debug kernel: [  266.456860] brcmfmac: CONSOLE: 026990.068 wl0.0: wlc_send_bar: seq 0x7c tid 0
Tue Oct  4 17:22:43 2016 kern.debug kernel: [  268.178234] brcmfmac: CONSOLE: 026991.783 pktid is NULL

# After recovering from A-MPDU thing firmware sends BRCMF_E_DEAUTH and
# BRCMF_E_DISASSOC_IND events.
# My smartphone never receives deauth/disassoc and it believes it's still
# connected to the AP.
Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275305] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 4
Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275354] brcmfmac: brcmf_notify_connect_status_ap event 12, reason 8
Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275865] brcmfmac: brcmf_cfg80211_del_key key index (0)
Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276177] brcmfmac: brcmf_cfg80211_del_key key index (0)
Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276188] brcmfmac: brcmf_cfg80211_del_key Ignore clearing of (never configured) key

# My smartphone starts sending packets. It seems brcmfmac refuses them due to
# STA not being connected and for each packet it reports BRCMF_E_DEAUTH to the
# driver.
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.000406] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001227] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001894] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.002594] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.003741] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004096] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004490] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004936] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

As you can see in above example I got more than just 3 BRCMF_E_DEAUTH reported
originally for BCM43602 firmware. But this isn't the worst case. In one extreme
situation I got 9714 of these events!


Mon Oct  3 09:10:04 2016 kern.err kernel: [227426.890053] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Mon Oct  3 09:10:04 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 472 identical lines were here)
Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 623 identical lines were here)
Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 443 identical lines were here)
Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 434 identical lines were here)
Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 577 identical lines were here)
Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 562 identical lines were here)
Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 451 identical lines were here)
Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 557 identical lines were here)
Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 426 identical lines were here)
Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 340 identical lines were here)
Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 115 identical lines were here)
Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 115 identical lines were here)
Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 150 identical lines were here)
Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 668 identical lines were here)
Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 602 identical lines were here)
Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 482 identical lines were here)
Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 419 identical lines were here)
Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 462 identical lines were here)
Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 584 identical lines were here)
Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 417 identical lines were here)
Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 485 identical lines were here)
Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 200 identical lines were here)
Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
(another 14 identical lines were here)

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-04 18:15 ` Rafał Miłecki
@ 2016-10-05  9:08   ` Arend Van Spriel
  2016-10-14  6:33     ` Rafał Miłecki
  2016-10-19 12:34   ` Rafał Miłecki
  1 sibling, 1 reply; 9+ messages in thread
From: Arend Van Spriel @ 2016-10-05  9:08 UTC (permalink / raw)
  To: Rafał Miłecki, linux-wireless, brcm80211 development

On 4-10-2016 20:15, Rafał Miłecki wrote:
> On 09/28/2015 11:00 AM, Rafał Miłecki wrote:
>> I'm using recent brcmfmac and brcmfmac43602-pcie.ap.bin that currently
>> sits in linux-firmware.git.
>>
>> In OpenWrt we have hostapd with a feature of banning STAs. It works in
>> a quite simple way. Whenever hostapd gets NL80211_CMD_NEW_STATION for
>> STA that is banned it sends NL80211_CMD_DEL_STATION.
>>
>> The problem is that in such case BCM43602 firmware happens to randomly
>> send more than 1 BRCMF_E_DEAUTH event. It seems it can send random
>> amount between 1 and 3. Looks a bit like some kind of race. It's
>> nothing really critical, just makes hostapd log a bit confusing.
>>
>> Could someone at Broadcom look at firmware source to see if you can
>> fix this, please?
> 
> Hey, I didn't get any reply on this for a year. I just saw similar
> problem with
> BCM4366. Below you will find a nice log with my extra comments.
> 
> Could take a look at this issue this time, please?

Can try.

> I think it may be another problem related to the A-MPDU thing (bug?) I
> reported
> in "AMPDU stalls with brcmfmac4366b-pcie.bin triggering WARNINGs" e-mail
> thread.

So what firmware version do you have? A colleague pointed me to firmware
fix that may be related so I want to know the target string to build.
Firmware version is in the bin file:

$ hexdump -C fw.bin | tail -40

Regards,
Arend

> # My smartphone remains in the same place (1 m from the AP) but there is
> some
> # connection/A-MPDU problem.
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509120] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: wl0.0 scb:0035ee78 tid:0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509250] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: wl0.0 dead_cnt 2 tx_in_transit 1 psm_mux
> 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509304] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 110486
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509346] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509411] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: txall 4 txbcn 0 txrts 0 rxcts 0 rsptmout
> 0 rxstrt 0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509477] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 4 0 0 0 0
> ifs_boff 0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509527] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509576] brcmfmac:
> CONSOLE: 026970.308 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509665] brcmfmac:
> CONSOLE: 026970.308 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due
> to no progress for 2 secs tx_in_transit 1
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509726] brcmfmac:
> CONSOLE: 026970.308 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1
> reason 39
> Tue Oct  4 17:22:41 2016 kern.debug kernel: [  266.456860] brcmfmac:
> CONSOLE: 026990.068 wl0.0: wlc_send_bar: seq 0x7c tid 0
> Tue Oct  4 17:22:43 2016 kern.debug kernel: [  268.178234] brcmfmac:
> CONSOLE: 026991.783 pktid is NULL
> 
> # After recovering from A-MPDU thing firmware sends BRCMF_E_DEAUTH and
> # BRCMF_E_DISASSOC_IND events.
> # My smartphone never receives deauth/disassoc and it believes it's still
> # connected to the AP.
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275305] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 4
> Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275354] brcmfmac:
> brcmf_notify_connect_status_ap event 12, reason 8
> Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275865] brcmfmac:
> brcmf_cfg80211_del_key key index (0)
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276177] brcmfmac:
> brcmf_cfg80211_del_key key index (0)
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276188] brcmfmac:
> brcmf_cfg80211_del_key Ignore clearing of (never configured) key
> 
> # My smartphone starts sending packets. It seems brcmfmac refuses them
> due to
> # STA not being connected and for each packet it reports BRCMF_E_DEAUTH
> to the
> # driver.
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.000406] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001227] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001894] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.002594] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.003741] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004096] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004490] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004936] brcmfmac:
> brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> 
> As you can see in above example I got more than just 3 BRCMF_E_DEAUTH
> reported
> originally for BCM43602 firmware. But this isn't the worst case. In one
> extreme
> situation I got 9714 of these events!
> 
> 
> Mon Oct  3 09:10:04 2016 kern.err kernel: [227426.890053] brcmfmac:
> brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x
> packets
> Mon Oct  3 09:10:04 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:06 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 472 identical lines were here)
> Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:07 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 623 identical lines were here)
> Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:08 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 443 identical lines were here)
> Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:09 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 434 identical lines were here)
> Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:10 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 577 identical lines were here)
> Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:11 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 562 identical lines were here)
> Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:12 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 451 identical lines were here)
> Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:13 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 557 identical lines were here)
> Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:14 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 426 identical lines were here)
> Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:15 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 340 identical lines were here)
> Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:16 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 115 identical lines were here)
> Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:17 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 115 identical lines were here)
> Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:18 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 150 identical lines were here)
> Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:19 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 668 identical lines were here)
> Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:20 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 602 identical lines were here)
> Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:21 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 482 identical lines were here)
> Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:22 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 419 identical lines were here)
> Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:23 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 462 identical lines were here)
> Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:24 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 584 identical lines were here)
> Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:25 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 417 identical lines were here)
> Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:26 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 485 identical lines were here)
> Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:27 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 200 identical lines were here)
> Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> Mon Oct  3 09:10:28 2016 daemon.info hostapd: wlan1: STA
> 3c:15:c2:dd:ce:de IEEE 802.11: disassociated
> (another 14 identical lines were here)

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-05  9:08   ` Arend Van Spriel
@ 2016-10-14  6:33     ` Rafał Miłecki
  2016-10-14 10:13       ` Arend Van Spriel
  0 siblings, 1 reply; 9+ messages in thread
From: Rafał Miłecki @ 2016-10-14  6:33 UTC (permalink / raw)
  To: Arend Van Spriel, linux-wireless, brcm80211 development

On 10/05/2016 11:08 AM, Arend Van Spriel wrote:
> On 4-10-2016 20:15, Rafał Miłecki wrote:
>> On 09/28/2015 11:00 AM, Rafał Miłecki wrote:
>>> I'm using recent brcmfmac and brcmfmac43602-pcie.ap.bin that currently
>>> sits in linux-firmware.git.
>>>
>>> In OpenWrt we have hostapd with a feature of banning STAs. It works in
>>> a quite simple way. Whenever hostapd gets NL80211_CMD_NEW_STATION for
>>> STA that is banned it sends NL80211_CMD_DEL_STATION.
>>>
>>> The problem is that in such case BCM43602 firmware happens to randomly
>>> send more than 1 BRCMF_E_DEAUTH event. It seems it can send random
>>> amount between 1 and 3. Looks a bit like some kind of race. It's
>>> nothing really critical, just makes hostapd log a bit confusing.
>>>
>>> Could someone at Broadcom look at firmware source to see if you can
>>> fix this, please?
>>
>> Hey, I didn't get any reply on this for a year. I just saw similar
>> problem with
>> BCM4366. Below you will find a nice log with my extra comments.
>>
>> Could take a look at this issue this time, please?
>
> Can try.

Thank you and sorry for my late reply! I'm back home now ready to provide any
extra details.


>> I think it may be another problem related to the A-MPDU thing (bug?) I
>> reported
>> in "AMPDU stalls with brcmfmac4366b-pcie.bin triggering WARNINGs" e-mail
>> thread.
>
> So what firmware version do you have? A colleague pointed me to firmware
> fix that may be related so I want to know the target string to build.
> Firmware version is in the bin file:
>
> $ hexdump -C fw.bin | tail -40

Well, I am pretty sure I was using the one released by Broadcom. Also my only
device with 4366b1 is DIR-885L. Once I was looking for 4366c0 firmware as
described in the kernel's bugzilla:
https://bugzilla.kernel.org/show_bug.cgi?id=135321
but I don't think I replaced them or anything.

Anyway, I repeated my tests paying attention to the firmware file. I'm pretty
sure it's the same one you can find in:
https://git.kernel.org/cgit/linux/kernel/git/firmware/linux-firmware.git/tree/brcm/brcmfmac4366b-pcie.bin

root@lede:/# md5sum /lib/firmware/brcm/brcmfmac4366b-pcie.bin
596f13d84e0042035cdb41202cfc385a  /lib/firmware/brcm/brcmfmac4366b-pcie.bin

root@lede:/# hexdump -C /lib/firmware/brcm/brcmfmac4366b-pcie.bin | tail -40
000f1670  40 00 03 07 07 07 40 00  03 07 07 07 40 00 03 07  |@.....@.....@...|
000f1680  07 07 40 00 72 61 74 65  73 65 6c 00 73 74 66 00  |..@.ratesel.stf.|
000f1690  63 63 6b 5f 6f 6e 65 63  6f 72 65 5f 74 78 00 74  |cck_onecore_tx.t|
000f16a0  65 6d 70 73 5f 70 65 72  69 6f 64 00 74 78 63 68  |emps_period.txch|
000f16b0  61 69 6e 00 72 78 63 68  61 69 6e 00 4d cc 07 00  |ain.rxchain.M...|
000f16c0  69 44 26 00 71 c9 07 00  91 c6 07 00 2d e9 ff 41  |iD&.q.......-..A|
000f16d0  80 46 4f f4 40 70 0d 46  17 46 1e 46 1f f5 4c ff  |.FO.@p.F.F.F..L.|
000f16e0  04 46 48 b9 28 46 1f f5  4d ff 02 46 23 49 24 48  |.FH.(F..M..F#I$H|
000f16f0  13 f7 24 fb 1e 20 3e e0  00 21 4f f4 40 72 12 f5  |..$.. >..!O.@r..|
000f1700  9d fd 0a 9b 40 46 00 93  04 f1 f8 03 01 93 04 f1  |....@F..........|
000f1710  fc 03 02 93 29 46 3a 46  33 46 e0 f7 5f fa c4 f8  |....)F:F3F.._...|
000f1720  f4 00 28 b9 17 48 15 49  0b 25 13 f7 07 fb 1e e0  |..(..H.I.%......|
000f1730  00 22 40 f6 12 01 00 25  22 f5 26 fb c4 f8 00 01  |."@....%".&.....|
000f1740  40 f6 12 01 d4 f8 f4 00  22 f5 06 fa c4 f8 e8 00  |@.......".......|
000f1750  20 46 51 f7 8d fb 0c 21  00 22 20 46 51 f7 94 fb  | FQ....!." FQ...|
000f1760  20 46 4d f7 69 f8 d4 f8  f4 00 df f7 d1 fe 20 46  | FM.i......... F|
000f1770  1f f5 16 ff 28 46 04 b0  bd e8 f0 81 88 17 2f 00  |....(F......../.|
000f1780  97 1b 2a 00 e2 f1 29 00  77 6c 63 5f 62 6d 61 63  |..*...).wlc_bmac|
000f1790  5f 70 72 6f 63 65 73 73  5f 75 63 6f 64 65 5f 73  |_process_ucode_s|
000f17a0  72 00 00 00 84 73 3b b4  0a 0a 45 ed 3d 22 90 56  |r....s;...E.=".V|
000f17b0  00 00 07 00 00 00 00 00  00 00 00 00 00 00 00 a4  |................|
000f17c0  91 7a c4 13 01 bd 32 08  01 00 34 33 36 36 62 31  |.z....2...4366b1|
000f17d0  2d 72 6f 6d 6c 2f 70 63  69 65 2d 61 67 2d 73 70  |-roml/pcie-ag-sp|
000f17e0  6c 69 74 72 78 2d 66 64  61 70 2d 6d 62 73 73 2d  |litrx-fdap-mbss-|
000f17f0  6d 66 70 2d 77 6e 6d 2d  6f 73 65 6e 2d 77 6c 31  |mfp-wnm-osen-wl1|
000f1800  31 6b 2d 77 6c 31 31 75  2d 74 78 62 66 2d 70 6b  |1k-wl11u-txbf-pk|
000f1810  74 63 74 78 2d 61 6d 73  64 75 74 78 2d 61 6d 70  |tctx-amsdutx-amp|
000f1820  64 75 72 65 74 72 79 2d  63 68 6b 64 32 68 64 6d  |duretry-chkd2hdm|
000f1830  61 2d 70 72 6f 70 74 78  73 74 61 74 75 73 2d 31  |a-proptxstatus-1|
000f1840  31 6e 70 72 6f 70 2d 6f  62 73 73 2d 64 62 77 73  |1nprop-obss-dbws|
000f1850  77 2d 72 69 6e 67 65 72  2d 64 6d 61 69 6e 64 65  |w-ringer-dmainde|
000f1860  78 31 36 2d 62 67 64 66  73 20 56 65 72 73 69 6f  |x16-bgdfs Versio|
000f1870  6e 3a 20 31 30 2e 31 30  2e 36 39 2e 32 33 37 20  |n: 10.10.69.237 |
000f1880  43 52 43 3a 20 34 62 63  34 38 63 37 62 20 44 61  |CRC: 4bc48c7b Da|
000f1890  74 65 3a 20 46 72 69 20  32 30 31 36 2d 30 31 2d  |te: Fri 2016-01-|
000f18a0  30 38 20 31 32 3a 35 35  3a 32 35 20 50 53 54 20  |08 12:55:25 PST |
000f18b0  55 63 6f 64 65 20 56 65  72 3a 20 31 30 37 33 2e  |Ucode Ver: 1073.|
000f18c0  35 33 31 20 46 57 49 44  3a 20 30 31 2d 63 34 37  |531 FWID: 01-c47|
000f18d0  61 39 31 61 34 0a 00 0d  01                       |a91a4....|
000f18d9

And there is a log using that very firmware I verified above.

# I got some timeouts, this time without ampdu_dbg or wlc_ampdu_watchdog
Fri Oct 14 06:09:07 2016 kern.err kernel: [  437.579199] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Fri Oct 14 06:09:08 2016 kern.err kernel: [  438.529199] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets

# Firmware sends BRCMF_E_DEAUTH and BRCMF_E_DISASSOC_IND events.
# My smartphone never receives deauth/disassoc and it believes it's still
# connected to the AP.
Fri Oct 14 06:09:12 2016 kern.debug kernel: [  442.276363] brcmfmac: CONSOLE: 027172.113 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Fri Oct 14 06:09:12 2016 kern.err kernel: [  442.276405] brcmfmac: brcmf_notify_connect_status_ap: event 5, reason 3
Fri Oct 14 06:09:12 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Fri Oct 14 06:09:12 2016 kern.err kernel: [  442.276447] brcmfmac: brcmf_notify_connect_status_ap: event 5, reason 3
Fri Oct 14 06:09:12 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

# My smartphone starts sending packets. Firmware reacts by sending
# BRCMF_E_DEAUTH events to the driver.
Fri Oct 14 06:10:57 2016 kern.err kernel: [  547.213534] brcmfmac: brcmf_notify_connect_status_ap: event 5, reason 7
Fri Oct 14 06:10:57 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Fri Oct 14 06:10:57 2016 kern.err kernel: [  547.321590] brcmfmac: brcmf_notify_connect_status_ap: event 5, reason 7
Fri Oct 14 06:10:57 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Fri Oct 14 06:10:57 2016 kern.err kernel: [  547.321918] brcmfmac: brcmf_notify_connect_status_ap: event 5, reason 7
Fri Oct 14 06:10:57 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-14  6:33     ` Rafał Miłecki
@ 2016-10-14 10:13       ` Arend Van Spriel
  2016-10-14 11:02         ` Rafał Miłecki
  2016-10-15 13:17         ` Rafał Miłecki
  0 siblings, 2 replies; 9+ messages in thread
From: Arend Van Spriel @ 2016-10-14 10:13 UTC (permalink / raw)
  To: Rafał Miłecki; +Cc: linux-wireless, brcm80211 development

Ok. Did you also try the firmware I sent you?

Regards,
Arend

On Fri, Oct 14, 2016 at 8:33 AM, Rafa=C5=82 Mi=C5=82ecki <zajec5@gmail.com>=
 wrote:
> On 10/05/2016 11:08 AM, Arend Van Spriel wrote:
>>
>> On 4-10-2016 20:15, Rafa=C5=82 Mi=C5=82ecki wrote:
>>>
>>> On 09/28/2015 11:00 AM, Rafa=C5=82 Mi=C5=82ecki wrote:
>>>>
>>>> I'm using recent brcmfmac and brcmfmac43602-pcie.ap.bin that currently
>>>> sits in linux-firmware.git.
>>>>
>>>> In OpenWrt we have hostapd with a feature of banning STAs. It works in
>>>> a quite simple way. Whenever hostapd gets NL80211_CMD_NEW_STATION for
>>>> STA that is banned it sends NL80211_CMD_DEL_STATION.
>>>>
>>>> The problem is that in such case BCM43602 firmware happens to randomly
>>>> send more than 1 BRCMF_E_DEAUTH event. It seems it can send random
>>>> amount between 1 and 3. Looks a bit like some kind of race. It's
>>>> nothing really critical, just makes hostapd log a bit confusing.
>>>>
>>>> Could someone at Broadcom look at firmware source to see if you can
>>>> fix this, please?
>>>
>>>
>>> Hey, I didn't get any reply on this for a year. I just saw similar
>>> problem with
>>> BCM4366. Below you will find a nice log with my extra comments.
>>>
>>> Could take a look at this issue this time, please?
>>
>>
>> Can try.
>
>
> Thank you and sorry for my late reply! I'm back home now ready to provide
> any
> extra details.
>
>
>>> I think it may be another problem related to the A-MPDU thing (bug?) I
>>> reported
>>> in "AMPDU stalls with brcmfmac4366b-pcie.bin triggering WARNINGs" e-mai=
l
>>> thread.
>>
>>
>> So what firmware version do you have? A colleague pointed me to firmware
>> fix that may be related so I want to know the target string to build.
>> Firmware version is in the bin file:
>>
>> $ hexdump -C fw.bin | tail -40
>
>
> Well, I am pretty sure I was using the one released by Broadcom. Also my
> only
> device with 4366b1 is DIR-885L. Once I was looking for 4366c0 firmware as
> described in the kernel's bugzilla:
> https://bugzilla.kernel.org/show_bug.cgi?id=3D135321
> but I don't think I replaced them or anything.
>
> Anyway, I repeated my tests paying attention to the firmware file. I'm
> pretty
> sure it's the same one you can find in:
> https://git.kernel.org/cgit/linux/kernel/git/firmware/linux-firmware.git/=
tree/brcm/brcmfmac4366b-pcie.bin
>
> root@lede:/# md5sum /lib/firmware/brcm/brcmfmac4366b-pcie.bin
> 596f13d84e0042035cdb41202cfc385a  /lib/firmware/brcm/brcmfmac4366b-pcie.b=
in
>
> root@lede:/# hexdump -C /lib/firmware/brcm/brcmfmac4366b-pcie.bin | tail =
-40
> 000f1670  40 00 03 07 07 07 40 00  03 07 07 07 40 00 03 07
> |@.....@.....@...|
> 000f1680  07 07 40 00 72 61 74 65  73 65 6c 00 73 74 66 00
> |..@.ratesel.stf.|
> 000f1690  63 63 6b 5f 6f 6e 65 63  6f 72 65 5f 74 78 00 74
> |cck_onecore_tx.t|
> 000f16a0  65 6d 70 73 5f 70 65 72  69 6f 64 00 74 78 63 68
> |emps_period.txch|
> 000f16b0  61 69 6e 00 72 78 63 68  61 69 6e 00 4d cc 07 00
> |ain.rxchain.M...|
> 000f16c0  69 44 26 00 71 c9 07 00  91 c6 07 00 2d e9 ff 41
> |iD&.q.......-..A|
> 000f16d0  80 46 4f f4 40 70 0d 46  17 46 1e 46 1f f5 4c ff
> |.FO.@p.F.F.F..L.|
> 000f16e0  04 46 48 b9 28 46 1f f5  4d ff 02 46 23 49 24 48
> |.FH.(F..M..F#I$H|
> 000f16f0  13 f7 24 fb 1e 20 3e e0  00 21 4f f4 40 72 12 f5  |..$..
>>..!O.@r..|
> 000f1700  9d fd 0a 9b 40 46 00 93 04 f1 f8 03 01 93 04 f1
> |....@F..........|
> 000f1710  fc 03 02 93 29 46 3a 46  33 46 e0 f7 5f fa c4 f8
> |....)F:F3F.._...|
> 000f1720  f4 00 28 b9 17 48 15 49  0b 25 13 f7 07 fb 1e e0
> |..(..H.I.%......|
> 000f1730  00 22 40 f6 12 01 00 25  22 f5 26 fb c4 f8 00 01
> |."@....%".&.....|
> 000f1740  40 f6 12 01 d4 f8 f4 00  22 f5 06 fa c4 f8 e8 00
> |@.......".......|
> 000f1750  20 46 51 f7 8d fb 0c 21  00 22 20 46 51 f7 94 fb  | FQ....!."
> FQ...|
> 000f1760  20 46 4d f7 69 f8 d4 f8  f4 00 df f7 d1 fe 20 46  | FM.i.......=
..
> F|
> 000f1770  1f f5 16 ff 28 46 04 b0  bd e8 f0 81 88 17 2f 00
> |....(F......../.|
> 000f1780  97 1b 2a 00 e2 f1 29 00  77 6c 63 5f 62 6d 61 63
> |..*...).wlc_bmac|
> 000f1790  5f 70 72 6f 63 65 73 73  5f 75 63 6f 64 65 5f 73
> |_process_ucode_s|
> 000f17a0  72 00 00 00 84 73 3b b4  0a 0a 45 ed 3d 22 90 56
> |r....s;...E.=3D".V|
> 000f17b0  00 00 07 00 00 00 00 00  00 00 00 00 00 00 00 a4
> |................|
> 000f17c0  91 7a c4 13 01 bd 32 08  01 00 34 33 36 36 62 31
> |.z....2...4366b1|
> 000f17d0  2d 72 6f 6d 6c 2f 70 63  69 65 2d 61 67 2d 73 70
> |-roml/pcie-ag-sp|
> 000f17e0  6c 69 74 72 78 2d 66 64  61 70 2d 6d 62 73 73 2d
> |litrx-fdap-mbss-|
> 000f17f0  6d 66 70 2d 77 6e 6d 2d  6f 73 65 6e 2d 77 6c 31
> |mfp-wnm-osen-wl1|
> 000f1800  31 6b 2d 77 6c 31 31 75  2d 74 78 62 66 2d 70 6b
> |1k-wl11u-txbf-pk|
> 000f1810  74 63 74 78 2d 61 6d 73  64 75 74 78 2d 61 6d 70
> |tctx-amsdutx-amp|
> 000f1820  64 75 72 65 74 72 79 2d  63 68 6b 64 32 68 64 6d
> |duretry-chkd2hdm|
> 000f1830  61 2d 70 72 6f 70 74 78  73 74 61 74 75 73 2d 31
> |a-proptxstatus-1|
> 000f1840  31 6e 70 72 6f 70 2d 6f  62 73 73 2d 64 62 77 73
> |1nprop-obss-dbws|
> 000f1850  77 2d 72 69 6e 67 65 72  2d 64 6d 61 69 6e 64 65
> |w-ringer-dmainde|
> 000f1860  78 31 36 2d 62 67 64 66  73 20 56 65 72 73 69 6f  |x16-bgdfs
> Versio|
> 000f1870  6e 3a 20 31 30 2e 31 30  2e 36 39 2e 32 33 37 20  |n: 10.10.69.=
237
> |
> 000f1880  43 52 43 3a 20 34 62 63  34 38 63 37 62 20 44 61  |CRC: 4bc48c7=
b
> Da|
> 000f1890  74 65 3a 20 46 72 69 20  32 30 31 36 2d 30 31 2d  |te: Fri
> 2016-01-|
> 000f18a0  30 38 20 31 32 3a 35 35  3a 32 35 20 50 53 54 20  |08 12:55:25 =
PST
> |
> 000f18b0  55 63 6f 64 65 20 56 65  72 3a 20 31 30 37 33 2e  |Ucode Ver:
> 1073.|
> 000f18c0  35 33 31 20 46 57 49 44  3a 20 30 31 2d 63 34 37  |531 FWID:
> 01-c47|
> 000f18d0  61 39 31 61 34 0a 00 0d  01                       |a91a4....|
> 000f18d9
>
> And there is a log using that very firmware I verified above.
>
> # I got some timeouts, this time without ampdu_dbg or wlc_ampdu_watchdog
> Fri Oct 14 06:09:07 2016 kern.err kernel: [  437.579199] brcmfmac:
> brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x pack=
ets
> Fri Oct 14 06:09:08 2016 kern.err kernel: [  438.529199] brcmfmac:
> brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x pack=
ets
>
> # Firmware sends BRCMF_E_DEAUTH and BRCMF_E_DISASSOC_IND events.
> # My smartphone never receives deauth/disassoc and it believes it's still
> # connected to the AP.
> Fri Oct 14 06:09:12 2016 kern.debug kernel: [  442.276363] brcmfmac:
> CONSOLE: 027172.113 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone
> !!??
> Fri Oct 14 06:09:12 2016 kern.err kernel: [  442.276405] brcmfmac:
> brcmf_notify_connect_status_ap: event 5, reason 3
> Fri Oct 14 06:09:12 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba=
:bc
> IEEE 802.11: disassociated
> Fri Oct 14 06:09:12 2016 kern.err kernel: [  442.276447] brcmfmac:
> brcmf_notify_connect_status_ap: event 5, reason 3
> Fri Oct 14 06:09:12 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba=
:bc
> IEEE 802.11: disassociated
>
> # My smartphone starts sending packets. Firmware reacts by sending
> # BRCMF_E_DEAUTH events to the driver.
> Fri Oct 14 06:10:57 2016 kern.err kernel: [  547.213534] brcmfmac:
> brcmf_notify_connect_status_ap: event 5, reason 7
> Fri Oct 14 06:10:57 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba=
:bc
> IEEE 802.11: disassociated
> Fri Oct 14 06:10:57 2016 kern.err kernel: [  547.321590] brcmfmac:
> brcmf_notify_connect_status_ap: event 5, reason 7
> Fri Oct 14 06:10:57 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba=
:bc
> IEEE 802.11: disassociated
> Fri Oct 14 06:10:57 2016 kern.err kernel: [  547.321918] brcmfmac:
> brcmf_notify_connect_status_ap: event 5, reason 7
> Fri Oct 14 06:10:57 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba=
:bc
> IEEE 802.11: disassociated

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-14 10:13       ` Arend Van Spriel
@ 2016-10-14 11:02         ` Rafał Miłecki
  2016-10-15 13:17         ` Rafał Miłecki
  1 sibling, 0 replies; 9+ messages in thread
From: Rafał Miłecki @ 2016-10-14 11:02 UTC (permalink / raw)
  To: Arend Van Spriel; +Cc: linux-wireless, brcm80211 development

On 14 October 2016 at 12:13, Arend Van Spriel
<arend.vanspriel@broadcom.com> wrote:
> Ok. Did you also try the firmware I sent you?

It gets more complex there, I'm still working on this. Will provide
more info later today.

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-14 10:13       ` Arend Van Spriel
  2016-10-14 11:02         ` Rafał Miłecki
@ 2016-10-15 13:17         ` Rafał Miłecki
  1 sibling, 0 replies; 9+ messages in thread
From: Rafał Miłecki @ 2016-10-15 13:17 UTC (permalink / raw)
  To: Arend Van Spriel; +Cc: linux-wireless, brcm80211 development

On 10/14/2016 12:13 PM, Arend Van Spriel wrote:
> Ok. Did you also try the firmware I sent you?

Hey again. Since you asked in public, I hope you don't mind me answering so.

So I tested experimental firmware I got from Arend (thank you!). It seems to
behave slightly differently but I still observe timeouts in
brcmf_netdev_wait_pend8021x.

Please note I modified brcmfmac to call brcmf_netdev_wait_pend8021x
continuously. This way it's not a matter of when send_key_to_dongle gets called.

I'll attach log of 11 cases where I saw wlc_ampdu_watchdog kicking in or just
a warning from brcmf_netdev_wait_pend8021x.

1st case: timeouts started occuring 16 seconds after wlc_ampdu_watchdog
2nd case: wlc_ampdu_tx_send_delba + timeout but without wlc_ampdu_watchdog
3rd case: timeouts 6 seconds after wlc_ampdu_watchdog
4th case: wlc_ampdu_watchdog without any timeout!
5th case: just one timeout
6th case: timeout between 2 wlc_ampdu_tx_send_delba + without any wlc_ampdu_watchdog
7th case: no timeout in brcmf_netdev_wait_pend8021x at all
8th case: it seems I can now see timeouts also before wlc_ampdu_watchdog + ampdu_dbg
9th case: similar to above
10th case: just 1 timeout *before* wlc_ampdu_watchdog + ampdu_dbg
11th case: wlc_ampdu_watchdog + ampdu_dbg without timeout at all

It's hard for me to say if it's much better. In some cases I didn't get timeouts
in brcmf_netdev_wait_pend8021x at all which is nice. In other ones timeouts were
occuring *before* wlc_ampdu_watchdog or *after* with some extra delay.

So something has changed, but some problem seems to remain.

#1
Sat Oct 15 10:40:34 2016 kern.debug kernel: [ 3444.338326] brcmfmac: CONSOLE: 030176.154 wl0: wlc_ampdu_resp_timeout: cleaning up resp tid 0 waiting forseq 0x6a8 for 1000 ms
Sat Oct 15 10:40:35 2016 kern.debug kernel: [ 3445.437653] brcmfmac: CONSOLE: 030177.254 wl0: wlc_ampdu_resp_timeout: cleaning up resp tid 0 waiting forseq 0x6af for 1000 ms
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659505] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: wl0.2 scb:0034946c tid:0
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659628] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659684] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109728
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659726] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659792] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: txall 1 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659860] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 14 0 0 0 0 ifs_boff 0
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659909] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.659960] brcmfmac: CONSOLE: 030178.476 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.660051] brcmfmac: CONSOLE: 030178.476 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 10:40:36 2016 kern.debug kernel: [ 3446.660113] brcmfmac: CONSOLE: 030178.476 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 10:40:39 2016 kern.debug kernel: [ 3449.657853] brcmfmac: CONSOLE: 030181.476 wl0: wlc_ampdu_watchdog: cleaning up tid 0 from poff
Sat Oct 15 10:40:54 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 10:40:55 2016 kern.err kernel: [ 3465.498648] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:40:56 2016 kern.err kernel: [ 3466.458647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:40:57 2016 kern.err kernel: [ 3467.409203] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:40:58 2016 kern.err kernel: [ 3468.368645] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:40:59 2016 kern.err kernel: [ 3469.319204] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:41:00 2016 kern.err kernel: [ 3470.278645] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:41:01 2016 kern.err kernel: [ 3471.229204] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:41:02 2016 kern.err kernel: [ 3472.188647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:41:03 2016 kern.err kernel: [ 3473.139229] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 10:41:03 2016 kern.debug kernel: [ 3473.657094] brcmfmac: CONSOLE: 030205.478 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 10:41:03 2016 kern.err kernel: [ 3473.657142] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 10:41:03 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#2
Sat Oct 15 11:36:56 2016 kern.debug kernel: [ 6826.183551] brcmfmac: CONSOLE: 033560.307 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 11:36:57 2016 kern.err kernel: [ 6827.368648] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:36:58 2016 kern.err kernel: [ 6828.328646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:36:59 2016 kern.err kernel: [ 6829.288646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:36:59 2016 kern.debug kernel: [ 6829.914889] brcmfmac: CONSOLE: 033564.041 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 11:36:59 2016 kern.err kernel: [ 6829.914961] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 11:36:59 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:36:59 2016 kern.err kernel: [ 6829.915141] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:36:59 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:36:59 2016 kern.err kernel: [ 6829.928441] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:36:59 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.095039] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.098203] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.311874] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.322031] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.324444] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.532318] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.547082] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.668501] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:00 2016 kern.err kernel: [ 6830.668911] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:00 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.123344] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.123725] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.124429] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.124724] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.125274] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.183095] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.183719] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.184148] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.184548] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.185028] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.185436] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.186032] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.186372] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.186842] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.187222] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.187749] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.188173] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.188523] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.188916] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.189432] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.189782] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.193480] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.193534] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.193558] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 11:37:01 2016 kern.err kernel: [ 6831.193580] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 11:37:01 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#3
Sat Oct 15 11:48:12 2016 kern.debug kernel: [ 7502.517302] brcmfmac: CONSOLE: 034236.934 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 11:48:13 2016 kern.debug kernel: [ 7503.866098] brcmfmac: CONSOLE: 034238.285 wl0: wlc_ampdu_resp_timeout: cleaning up resp tid 0 waiting forseq 0xd84 for 1000 ms
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528279] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: wl0.2 scb:00346afc tid:0
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528404] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528460] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109640
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528503] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528569] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: txall 5 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528699] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 14 0 0 0 0 ifs_boff 0
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528752] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528802] brcmfmac: CONSOLE: 034243.949 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528893] brcmfmac: CONSOLE: 034243.949 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 11:48:19 2016 kern.debug kernel: [ 7509.528955] brcmfmac: CONSOLE: 034243.949 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 11:48:25 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 11:48:25 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 11:48:25 2016 kern.err kernel: [ 7516.038647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:26 2016 kern.err kernel: [ 7516.998666] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:27 2016 kern.err kernel: [ 7517.949204] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:28 2016 kern.err kernel: [ 7518.908647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:29 2016 kern.err kernel: [ 7519.868646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:30 2016 kern.err kernel: [ 7520.828649] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:31 2016 kern.err kernel: [ 7521.788645] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:32 2016 kern.err kernel: [ 7522.748646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:33 2016 kern.err kernel: [ 7523.699209] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 11:48:34 2016 kern.debug kernel: [ 7524.545280] brcmfmac: CONSOLE: 034258.961 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 11:48:34 2016 kern.err kernel: [ 7524.545327] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 11:48:34 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#4
Sat Oct 15 11:53:42 2016 kern.debug kernel: [ 7832.709896] brcmfmac: CONSOLE: 034567.239 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 11:53:43 2016 kern.debug kernel: [ 7833.155136] brcmfmac: CONSOLE: 034567.686 wl0: wlc_ampdu_resp_timeout: cleaning up resp tid 0 waiting forseq 0xe6e for 1000 ms
Sat Oct 15 11:53:55 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.724898] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: wl0.2 scb:0034946c tid:0
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725022] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725078] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109071
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725120] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725187] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: txall 28 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725254] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 2 0 2 0 0 ifs_boff 0
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725304] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725356] brcmfmac: CONSOLE: 034580.251 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725447] brcmfmac: CONSOLE: 034580.251 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 11:53:55 2016 kern.debug kernel: [ 7845.725510] brcmfmac: CONSOLE: 034580.251 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 11:53:55 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 11:53:58 2016 kern.debug kernel: [ 7848.754986] brcmfmac: CONSOLE: 034583.290 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 11:53:58 2016 kern.err kernel: [ 7848.755041] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 11:53:58 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#5
Sat Oct 15 12:01:24 2016 kern.debug kernel: [ 8294.512509] brcmfmac: CONSOLE: 035029.214 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:01:25 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:01:26 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:01:27 2016 kern.debug kernel: [ 8297.522873] brcmfmac: CONSOLE: 035032.228 wl0: wlc_ampdu_resp_timeout: cleaning up resp tid 0 waiting forseq 0xcd8 for 1000 ms
Sat Oct 15 12:01:27 2016 kern.err kernel: [ 8297.809204] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:01:28 2016 kern.err kernel: [ 8298.759205] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:01:29 2016 kern.err kernel: [ 8299.709203] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709455] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: wl0.2 scb:00346afc tid:0
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709575] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709632] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109600
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709676] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709742] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: txall 8 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709810] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 12 0 0 0 0 ifs_boff 0
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709860] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.709911] brcmfmac: CONSOLE: 035034.226 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.710002] brcmfmac: CONSOLE: 035034.226 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 12:01:29 2016 kern.debug kernel: [ 8299.710063] brcmfmac: CONSOLE: 035034.226 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.668646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.845503] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 12:01:30 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.846117] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:01:30 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.846234] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:01:30 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.846848] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:01:30 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:01:30 2016 kern.debug kernel: [ 8300.845457] brcmfmac: CONSOLE: 035035.551 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.847118] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:01:30 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:01:30 2016 kern.err kernel: [ 8300.876364] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:01:30 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#6
Sat Oct 15 12:08:54 2016 kern.debug kernel: [ 8744.163589] brcmfmac: CONSOLE: 035479.101 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:08:55 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:08:55 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:08:57 2016 kern.err kernel: [ 8747.968646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:08:57 2016 kern.debug kernel: [ 8747.968977] brcmfmac: CONSOLE: 035482.107 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:08:59 2016 kern.debug kernel: [ 8749.033058] brcmfmac: CONSOLE: 035483.975 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 12:08:59 2016 kern.err kernel: [ 8749.033112] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 12:08:59 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.785827] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.786446] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.787826] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.788462] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.832697] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.832956] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.833657] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.833711] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.834027] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.834453] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.834591] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.835375] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.835583] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.836126] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.836518] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.836889] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.837295] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.837686] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.838107] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.838513] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.838884] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.839350] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.839733] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
Sat Oct 15 12:09:02 2016 kern.err kernel: [ 8752.840185] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 7
Sat Oct 15 12:09:02 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#7
Sat Oct 15 12:11:20 2016 kern.debug kernel: [ 8890.348071] brcmfmac: CONSOLE: 035625.342 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:11:21 2016 kern.debug kernel: [ 8891.391863] brcmfmac: CONSOLE: 035626.393 wl0: wlc_ampdu_resp_timeout: cleaning up resp tid 0 waiting forseq 0xeba for 1000 ms
Sat Oct 15 12:11:25 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:11:26 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:11:29 2016 kern.debug kernel: [ 8899.083518] brcmfmac: CONSOLE: 035634.087 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 12:11:29 2016 kern.err kernel: [ 8899.083568] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 12:11:29 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#8
Sat Oct 15 12:22:25 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:22:25 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:22:27 2016 kern.err kernel: [ 9557.228645] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:28 2016 kern.err kernel: [ 9558.188646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451027] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: wl0.2 scb:0034777c tid:0
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451150] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451206] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109206
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451249] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451317] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: txall 33 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451383] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 4 0 0 0 0 ifs_boff 0
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451433] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451484] brcmfmac: CONSOLE: 036293.506 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451575] brcmfmac: CONSOLE: 036293.506 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 12:22:28 2016 kern.debug kernel: [ 9558.451636] brcmfmac: CONSOLE: 036293.506 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:22:29 2016 kern.err kernel: [ 9559.148655] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:30 2016 kern.err kernel: [ 9560.108648] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:31 2016 kern.err kernel: [ 9561.068647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:31 2016 kern.debug kernel: [ 9561.253087] brcmfmac: CONSOLE: 036296.512 wl0: wlc_ampdu_watchdog: cleaning up tid 0 from poff
Sat Oct 15 12:22:32 2016 kern.err kernel: [ 9562.028646] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:32 2016 kern.err kernel: [ 9562.988647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:33 2016 kern.debug kernel: [ 9563.258653] brcmfmac: CONSOLE: 036298.516 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 12:22:33 2016 kern.err kernel: [ 9563.258699] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 12:22:33 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#9
Sat Oct 15 12:22:55 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:22:56 2016 kern.err kernel: [ 9586.728647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:22:57 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280576] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: wl0.2 scb:0034946c tid:0
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280701] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280756] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109237
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280798] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280865] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: txall 47 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280933] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 7 0 0 0 0 ifs_boff 0
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.280982] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.281033] brcmfmac: CONSOLE: 036337.561 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.281124] brcmfmac: CONSOLE: 036337.561 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 12:23:12 2016 kern.debug kernel: [ 9602.281185] brcmfmac: CONSOLE: 036337.561 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.283602] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: wl0.2 scb:0034946c tid:0
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.283727] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.283781] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109686
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.283824] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.283890] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: txall 1 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.283957] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 3 0 0 0 0 ifs_boff 0
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.284008] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.284058] brcmfmac: CONSOLE: 036347.569 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.284150] brcmfmac: CONSOLE: 036347.569 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 12:23:22 2016 kern.debug kernel: [ 9612.284212] brcmfmac: CONSOLE: 036347.569 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
Sat Oct 15 12:23:25 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:23:26 2016 kern.err kernel: [ 9616.738647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:23:27 2016 kern.err kernel: [ 9617.698647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:23:28 2016 kern.err kernel: [ 9618.649206] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:23:28 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:23:29 2016 kern.err kernel: [ 9619.606333] brcmfmac: brcmf_notify_connect_status_ap: event ASSOC_IND (8), reason 0
Sat Oct 15 12:23:29 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: associated
Sat Oct 15 12:23:32 2016 kern.debug kernel: [ 9622.781918] brcmfmac: CONSOLE: 036358.071 wl0: Proxy STA 78:d6:f0:9b:ba:bc link is already gone !!??
Sat Oct 15 12:23:32 2016 kern.err kernel: [ 9622.781972] brcmfmac: brcmf_notify_connect_status_ap: event DEAUTH (5), reason 3
Sat Oct 15 12:23:32 2016 daemon.info hostapd: wlan1-1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

#10
Sat Oct 15 12:27:25 2016 daemon.info hostapd: wlan1-1: STA 88:53:2e:50:50:00 WPA: group key handshake completed (RSN)
Sat Oct 15 12:27:28 2016 kern.err kernel: [ 9858.338647] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
Sat Oct 15 12:27:28 2016 daemon.info hostapd: wlan1-1: STA 84:38:38:e4:b5:ea WPA: group key handshake completed (RSN)
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.429832] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: wl0.2 scb:0034946c tid:0
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.429956] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430011] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 109632
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430054] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430121] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: txall 4 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430187] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 4 0 0 0 0 ifs_boff 0
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430238] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430289] brcmfmac: CONSOLE: 036596.854 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430380] brcmfmac: CONSOLE: 036596.854 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 12:27:31 2016 kern.debug kernel: [ 9861.430441] brcmfmac: CONSOLE: 036596.854 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39

#11
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438336] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: wl0.2 scb:0034946c tid:0
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438461] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: wl0.2 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438516] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 107539
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438559] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438705] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: txall 13 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438782] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 11 0 0 0 0 ifs_boff 0
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438833] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438883] brcmfmac: CONSOLE: 036603.864 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.438975] brcmfmac: CONSOLE: 036603.864 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
Sat Oct 15 12:27:38 2016 kern.debug kernel: [ 9868.439037] brcmfmac: CONSOLE: 036603.864 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-04 18:15 ` Rafał Miłecki
  2016-10-05  9:08   ` Arend Van Spriel
@ 2016-10-19 12:34   ` Rafał Miłecki
  2016-11-02 19:42     ` Arend Van Spriel
  1 sibling, 1 reply; 9+ messages in thread
From: Rafał Miłecki @ 2016-10-19 12:34 UTC (permalink / raw)
  To: linux-wireless, brcm80211 development

[-- Attachment #1: Type: text/plain, Size: 5436 bytes --]

On 10/04/2016 08:15 PM, Rafał Miłecki wrote:
> # My smartphone remains in the same place (1 m from the AP) but there is some
> # connection/A-MPDU problem.
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509120] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: wl0.0 scb:0035ee78 tid:0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509250] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: wl0.0 dead_cnt 2 tx_in_transit 1 psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0 cpbusy 0x0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509304] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 110486
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509346] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509411] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: txall 4 txbcn 0 txrts 0 rxcts 0 rsptmout 0 rxstrt 0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509477] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 4 0 0 0 0 ifs_boff 0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509527] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509576] brcmfmac: CONSOLE: 026970.308 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509665] brcmfmac: CONSOLE: 026970.308 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs tx_in_transit 1
> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509726] brcmfmac: CONSOLE: 026970.308 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1 reason 39
> Tue Oct  4 17:22:41 2016 kern.debug kernel: [  266.456860] brcmfmac: CONSOLE: 026990.068 wl0.0: wlc_send_bar: seq 0x7c tid 0
> Tue Oct  4 17:22:43 2016 kern.debug kernel: [  268.178234] brcmfmac: CONSOLE: 026991.783 pktid is NULL
>
> # After recovering from A-MPDU thing firmware sends BRCMF_E_DEAUTH and
> # BRCMF_E_DISASSOC_IND events.
> # My smartphone never receives deauth/disassoc and it believes it's still
> # connected to the AP.
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275305] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 4
> Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275354] brcmfmac: brcmf_notify_connect_status_ap event 12, reason 8
> Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275865] brcmfmac: brcmf_cfg80211_del_key key index (0)
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276177] brcmfmac: brcmf_cfg80211_del_key key index (0)
> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276188] brcmfmac: brcmf_cfg80211_del_key Ignore clearing of (never configured) key
>
> # My smartphone starts sending packets. It seems brcmfmac refuses them due to
> # STA not being connected and for each packet it reports BRCMF_E_DEAUTH to the
> # driver.
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.000406] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001227] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001894] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.002594] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.003741] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004096] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004490] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004936] brcmfmac: brcmf_notify_connect_status_ap event 5, reason 7
> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated

I just got 400+ messages like this:
wlan1: STA 84:38:38:e4:b5:ea IEEE 802.11: disassociated
this time I was lucky enough to have monitor mode running on some independent
notebook and I got it recorded.

I'm attaching pcapng (Wireshark dump) file. You can see a lot of
Deauthentication frames flying both ways with a reason code 0x0006 (Class 2
frame received from nonauthenticated STA).

I think this reason code seems to match my suspicions: STA didn't realize it was
disconnected and it kept sending packets. Firmware reacted sending Deauth frames

[-- Attachment #2: deauth.tar.bz2 --]
[-- Type: application/x-bzip, Size: 5424 bytes --]

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: BCM43602 firmware reports multiple BRCMF_E_DEAUTH
  2016-10-19 12:34   ` Rafał Miłecki
@ 2016-11-02 19:42     ` Arend Van Spriel
  0 siblings, 0 replies; 9+ messages in thread
From: Arend Van Spriel @ 2016-11-02 19:42 UTC (permalink / raw)
  To: Rafał Miłecki, linux-wireless, brcm80211 development

On 19-10-2016 14:34, Rafał Miłecki wrote:
> On 10/04/2016 08:15 PM, Rafał Miłecki wrote:
>> # My smartphone remains in the same place (1 m from the AP) but there
>> is some
>> # connection/A-MPDU problem.
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509120] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: wl0.0 scb:0035ee78 tid:0
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509250] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: wl0.0 dead_cnt 2 tx_in_transit 1
>> psm_mux 0xfff0 aqmqmap 0x0x101 aqmfifo_status 0x0x4000 fifordy 0x0
>> cpbusy 0x0
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509304] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: ifsstat 0xaf nav_stat 0x0 txop 110486
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509346] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: pktpend: 0 0 0 0 0 ap 1
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509411] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: txall 4 txbcn 0 txrts 0 rxcts 0
>> rsptmout 0 rxstrt 0
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509477] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: cwcur0-3 f f 7 3 bslots cur/0-3 4 0 0 0
>> 0 ifs_boff 0
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509527] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: again1 ifsstat 0xaf nav_stat 0x0
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509576] brcmfmac:
>> CONSOLE: 026970.308 ampdu_dbg: again2 ifsstat 0xaf nav_stat 0x0
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509665] brcmfmac:
>> CONSOLE: 026970.308 wl0: wlc_ampdu_watchdog: cleaning up ini tid 0 due
>> to no progress for 2 secs tx_in_transit 1
>> Tue Oct  4 17:22:22 2016 kern.debug kernel: [  247.509726] brcmfmac:
>> CONSOLE: 026970.308 wl0: wlc_ampdu_tx_send_delba: tid 0 initiator 1
>> reason 39
>> Tue Oct  4 17:22:41 2016 kern.debug kernel: [  266.456860] brcmfmac:
>> CONSOLE: 026990.068 wl0.0: wlc_send_bar: seq 0x7c tid 0
>> Tue Oct  4 17:22:43 2016 kern.debug kernel: [  268.178234] brcmfmac:
>> CONSOLE: 026991.783 pktid is NULL
>>
>> # After recovering from A-MPDU thing firmware sends BRCMF_E_DEAUTH and
>> # BRCMF_E_DISASSOC_IND events.
>> # My smartphone never receives deauth/disassoc and it believes it's still
>> # connected to the AP.
>> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275305] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 4
>> Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275354] brcmfmac:
>> brcmf_notify_connect_status_ap event 12, reason 8
>> Tue Oct  4 17:23:24 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.275865] brcmfmac:
>> brcmf_cfg80211_del_key key index (0)
>> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276177] brcmfmac:
>> brcmf_cfg80211_del_key key index (0)
>> Tue Oct  4 17:23:24 2016 kern.debug kernel: [  309.276188] brcmfmac:
>> brcmf_cfg80211_del_key Ignore clearing of (never configured) key
>>
>> # My smartphone starts sending packets. It seems brcmfmac refuses them
>> due to
>> # STA not being connected and for each packet it reports
>> BRCMF_E_DEAUTH to the
>> # driver.
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.000406] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001227] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.001894] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.002594] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.003741] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004096] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004490] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
>> Tue Oct  4 17:23:58 2016 kern.debug kernel: [  343.004936] brcmfmac:
>> brcmf_notify_connect_status_ap event 5, reason 7
>> Tue Oct  4 17:23:58 2016 daemon.info hostapd: wlan1: STA
>> 78:d6:f0:9b:ba:bc IEEE 802.11: disassociated
> 
> I just got 400+ messages like this:
> wlan1: STA 84:38:38:e4:b5:ea IEEE 802.11: disassociated
> this time I was lucky enough to have monitor mode running on some
> independent
> notebook and I got it recorded.
> 
> I'm attaching pcapng (Wireshark dump) file. You can see a lot of
> Deauthentication frames flying both ways with a reason code 0x0006 (Class 2
> frame received from nonauthenticated STA).
> 
> I think this reason code seems to match my suspicions: STA didn't
> realize it was
> disconnected and it kept sending packets. Firmware reacted sending
> Deauth frames

Hi Rafał,

Staring at the wireshark dump I can not follow your suspicion above.
Where are the packets that STA was sending. The 802.11 spec mentions
there can be more deauth frames being transmitted during the deauth
procedure. So it seems they get stuck in the deauth procedure for some
reason.

Regards,
Arend

^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2016-11-02 19:42 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-09-28  9:00 BCM43602 firmware reports multiple BRCMF_E_DEAUTH Rafał Miłecki
2016-10-04 18:15 ` Rafał Miłecki
2016-10-05  9:08   ` Arend Van Spriel
2016-10-14  6:33     ` Rafał Miłecki
2016-10-14 10:13       ` Arend Van Spriel
2016-10-14 11:02         ` Rafał Miłecki
2016-10-15 13:17         ` Rafał Miłecki
2016-10-19 12:34   ` Rafał Miłecki
2016-11-02 19:42     ` Arend Van Spriel

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.