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ł
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)
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
On 14 October 2016 at 12:13, Arend Van Spriel
<[email protected]> 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.
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
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 <[email protected]>=
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
> |[email protected].|
> 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
> |[email protected].|
> 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
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 |[email protected].|
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 |[email protected].|
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
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)
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