[REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux]

Hi,

Commit 1204aa17f3b4 ("brcmfmac: set WIPHY_FLAG_HAVE_AP_SME flag")
appears to have broken hostapd 2.4, thereby causing a user visible
regression when upgrading across the 4.18 boundary (e.g. 4.13 to
4.19).

The presence of this flag causes nl80211 to add an additional
attribute to the netlink wiphy reply:

                if ((rdev->wiphy.flags & WIPHY_FLAG_HAVE_AP_SME) &&
                    nla_put_u32(msg, NL80211_ATTR_DEVICE_AP_SME,
                                rdev->wiphy.ap_sme_capa))
                        goto nla_put_failure;

which is then parsed by hostapd using a presence/absence test for
this property (the value of the property is meaningless):

        nla_parse(tb, NL80211_ATTR_MAX, genlmsg_attrdata(gnlh, 0),
                  genlmsg_attrlen(gnlh, 0), NULL);
...
        if (tb[NL80211_ATTR_DEVICE_AP_SME])
                info->device_ap_sme = 1;

This causes hostapd to then attempt to subscribe to management
frames (via nl80211_mgmt_subscribe_ap_dev_sme()):

        if (nl80211_register_frame(bss, bss->nl_mgmt,
                                   (WLAN_FC_TYPE_MGMT << 2) |
                                   (WLAN_FC_STYPE_ACTION << 4),
                                   NULL, 0) < 0)

and brcmfmac does not support passing any management frames in AP
mode (brcmf_txrx_stypes[NL80211_IFTYPE_AP] is empty).  That causes
nl80211_register_frame() to fail, and hostapd fails to initialise.

Checking the hostapd versions (including up to 2.7) shows that
nothing has changed, so this change has broken the ability for
hostapd to be used with brcmfmac - thereby causing a user-visible
regression.

Can this commit be reverted to fix this regression please?

Thanks.

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Kalle Valo]

Arend Van Spriel <arend.vanspriel@broadcom.com> writes:

> Response using Gmail on phone

Unfortunately it had HTML and not sure if it made it to the list, so
copying your response in full below just in case. Russell, does the
commit below fix your problem?

861cb5eb467f brcmfmac: Fix access point mode

> Op ma 24 dec. 2018 12:09 schreef Russell King - ARM Linux
> <linux@armlinux.org.uk:
>
>     Hi,
>     
>     Commit 1204aa17f3b4 ("brcmfmac: set WIPHY_FLAG_HAVE_AP_SME flag")
>     appears to have broken hostapd 2.4, thereby causing a user visible
>     regression when upgrading across the 4.18 boundary (e.g. 4.13 to
>     4.19).
>     
>     The presence of this flag causes nl80211 to add an additional
>     attribute to the netlink wiphy reply:
>     
>     if ((rdev->wiphy.flags & WIPHY_FLAG_HAVE_AP_SME) &&
>     nla_put_u32(msg, NL80211_ATTR_DEVICE_AP_SME,
>     rdev->wiphy.ap_sme_capa))
>     goto nla_put_failure;
>     
>     which is then parsed by hostapd using a presence/absence test for
>     this property (the value of the property is meaningless):
>     
>     nla_parse(tb, NL80211_ATTR_MAX, genlmsg_attrdata(gnlh, 0),
>     genlmsg_attrlen(gnlh, 0), NULL);
>     ...
>     if (tb[NL80211_ATTR_DEVICE_AP_SME])
>     info->device_ap_sme = 1;
>     
>     This causes hostapd to then attempt to subscribe to management
>     frames (via nl80211_mgmt_subscribe_ap_dev_sme()):
>     
>     if (nl80211_register_frame(bss, bss->nl_mgmt,
>     (WLAN_FC_TYPE_MGMT << 2) |
>     (WLAN_FC_STYPE_ACTION << 4),
>     NULL, 0) < 0)
>     
>     and brcmfmac does not support passing any management frames in AP
>     mode (brcmf_txrx_stypes[NL80211_IFTYPE_AP] is empty). That causes
>     nl80211_register_frame() to fail, and hostapd fails to initialise.
>     
>     Checking the hostapd versions (including up to 2.7) shows that
>     nothing has changed, so this change has broken the ability for
>     hostapd to be used with brcmfmac - thereby causing a user-visible
>     regression.
>     
>     Can this commit be reverted to fix this regression please?
>     
>
> A patch has already been applied [1] to wireless-drivers-next repo.
>
> Regards,
> Arend
>
> [1] https://patchwork.kernel.org/patch/10726965/

-- 
Kalle Valo

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux]

On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
> Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
> 
> > Response using Gmail on phone
> 
> Unfortunately it had HTML and not sure if it made it to the list, so
> copying your response in full below just in case. Russell, does the
> commit below fix your problem?
> 
> 861cb5eb467f brcmfmac: Fix access point mode

From a quick test this evening, it does seem to allow brcmfmac to work
with hostapd again, which is good news.

However, I've been seeing other issues with the brcmfmac over the course
of the last week, which needs the brcmfmac module to be removed and
re-loaded to rescue the situation - ultimately, it means that running
brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
patch - we will see how 4.20 with the above mentioned patch behaves over
the coming week.

[1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[1045006.357728] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[1049743.889412] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
[1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110

Then I'd reload the module and reconfigure the networking:

[1078473.212335] brcmfmac: brcmf_fil_cmd_data: bus is down. we have nothing to do.
[1078473.222473] brcmfmac: brcmf_fil_cmd_data: bus is down. we have nothing to do.
[1078473.230066] brcmfmac: brcmf_cfg80211_get_channel: chanspec failed (-5)
[1078473.423466] brcmfmac: F1 signature read @0x18000000=0x16044330
[1078473.448873] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4330-sdio
for chip BCM4330/4
[1078473.794979] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4330-sdio
for chip BCM4330/4
[1078473.804750] brcmfmac mmc0:0001:1: Direct firmware load for brcm/brcmfmac4330-sdio.clm_blob failed with error -2
[1078473.817127] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[1078473.831682] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Oct 25 2011 19:34:12 version 5.90.125.104
[1078474.107922] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1078474.229331] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1078474.782310] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1078476.471994] brcmfmac: brcmf_p2p_create_p2pdev: timeout occurred
[1078476.478270] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-5
[1078476.512507] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1078478.091188] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1078478.139786] netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
[1078478.349878] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[1078478.837386] brcmfmac: brcmf_vif_set_mgmt_ie: vndr ie set error : -52
[1078478.848627] brcmfmac: brcmf_vif_set_mgmt_ie: vndr ie set error : -52
[1078478.906905] netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
[1078484.468666] brcmfmac: brcmf_vif_set_mgmt_ie: vndr ie set error : -52
[1078484.479804] brcmfmac: brcmf_vif_set_mgmt_ie: vndr ie set error : -52
[1078485.038287] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1078485.398249] br0: port 2(wlan0) entered blocking state
[1078485.403675] br0: port 2(wlan0) entered forwarding state
[1127330.284075] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[1133420.775451] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[1148684.418698] brcmfmac: send_key_to_dongle: wsec_key error (-110)

... reloading again ...

[1163361.156133] br0: port 2(wlan0) entered disabled state
[1163361.245369] device wlan0 left promiscuous mode
[1163361.250437] br0: port 2(wlan0) entered disabled state
[1163361.285328] brcmfmac: brcmf_cfg80211_change_iface: WLC_SET_INFRA error (-5)[1163361.293839] brcmfmac: brcmf_fil_cmd_data: bus is down. we have nothing to do.
[1163361.301738] brcmfmac: brcmf_fil_cmd_data: bus is down. we have nothing to do.
[1163361.309439] brcmfmac: brcmf_cfg80211_get_channel: chanspec failed (-5)
[1163361.317291] brcmfmac: brcmf_fil_cmd_data: bus is down. we have nothing to do.
[1163361.324788] brcmfmac: brcmf_cfg80211_get_channel: chanspec failed (-5)
[1163361.333679] brcmfmac: brcmf_fil_cmd_data: bus is down. we have nothing to do.
[1163361.341189] brcmfmac: brcmf_cfg80211_get_channel: chanspec failed (-5)
[1163361.529825] brcmfmac: F1 signature read @0x18000000=0x16044330
[1163361.547495] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4330-sdio for chip BCM4330/4
[1163361.894540] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4330-sdio for chip BCM4330/4
[1163361.903540] brcmfmac mmc0:0001:1: Direct firmware load for brcm/brcmfmac4330-sdio.clm_blob failed with error -2
[1163361.914067] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[1163361.930371] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Oct 25 2011 19:34:12 version 5.90.125.104
[1163362.173752] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1163362.295305] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1163362.862063] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1163364.576933] brcmfmac: brcmf_p2p_create_p2pdev: timeout occurred
[1163364.583207] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-5
[1163365.139274] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[1163365.170973] br0: port 2(wlan0) entered blocking state
[1163365.176371] br0: port 2(wlan0) entered disabled state
[1163365.184962] device wlan0 entered promiscuous mode
[1163365.469716] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[1163365.480003] br0: port 2(wlan0) entered blocking state
[1163365.485371] br0: port 2(wlan0) entered forwarding state
[1242693.543254] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[1242696.102911] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[1242696.111775] brcmfmac: brcmf_cfg80211_get_station: GET STA INFO failed, -110
[1331361.789147] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1331362.779876] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1331958.234110] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1332559.191969] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1333160.149868] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1333761.111701] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1334362.065533] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[1334963.023362] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets

Any thoughts on what would cause this?

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/9/2019 12:26 AM, Russell King - ARM Linux wrote:
> On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
>> Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
>>
>>> Response using Gmail on phone
>>
>> Unfortunately it had HTML and not sure if it made it to the list, so
>> copying your response in full below just in case. Russell, does the
>> commit below fix your problem?
>>
>> 861cb5eb467f brcmfmac: Fix access point mode
> 
>  From a quick test this evening, it does seem to allow brcmfmac to work
> with hostapd again, which is good news.
> 
> However, I've been seeing other issues with the brcmfmac over the course
> of the last week, which needs the brcmfmac module to be removed and
> re-loaded to rescue the situation - ultimately, it means that running
> brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
> patch - we will see how 4.20 with the above mentioned patch behaves over
> the coming week.
> 
> [1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> [1045006.357728] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> [1049743.889412] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> [1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> [1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110

Is this with hostapd? If so, this br0 message suggest you let hostapd 
create a bridge, is that correct? Just trying to get a good picture in 
case I want to replicate things over here although I am pretty sure I do 
not have the same platform lying around here. Although, what platform do 
you have?

The timeout (-110) error can mean either firmware crashed or the sdio 
host controller went in limbo. If this happens again on 4.20 (or 
5.0-rc1), you could build the driver with CONFIG_BRCMDBG and load the 
driver with debug=0x100010. If it is a firmware crash it should show up 
in the log.

Regards,
Arend

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/8/2019 5:40 PM, Kalle Valo wrote:
> Arend Van Spriel<arend.vanspriel@broadcom.com>  writes:
> 
>> Response using Gmail on phone
> Unfortunately it had HTML and not sure if it made it to the list, so
> copying your response in full below just in case. Russell, does the
> commit below fix your problem?

Thanks, Kalle

I am pretty sure it did not make it to the list as I got a bounce 
message from it. I use my phone sparingly to reply.

Gr. AvS

> 861cb5eb467f brcmfmac: Fix access point mode
> 

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux]

On Wed, Jan 09, 2019 at 11:27:31AM +0100, Arend Van Spriel wrote:
> On 1/9/2019 12:26 AM, Russell King - ARM Linux wrote:
> >On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
> >>Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
> >>
> >>>Response using Gmail on phone
> >>
> >>Unfortunately it had HTML and not sure if it made it to the list, so
> >>copying your response in full below just in case. Russell, does the
> >>commit below fix your problem?
> >>
> >>861cb5eb467f brcmfmac: Fix access point mode
> >
> > From a quick test this evening, it does seem to allow brcmfmac to work
> >with hostapd again, which is good news.
> >
> >However, I've been seeing other issues with the brcmfmac over the course
> >of the last week, which needs the brcmfmac module to be removed and
> >re-loaded to rescue the situation - ultimately, it means that running
> >brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
> >patch - we will see how 4.20 with the above mentioned patch behaves over
> >the coming week.
> >
> >[1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> >[1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> >[1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> >[1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> >[1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> >[1045006.357728] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> >[1049743.889412] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> >[1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> >[1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> >[1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> >[1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> 
> Is this with hostapd? If so, this br0 message suggest you let hostapd create
> a bridge, is that correct? Just trying to get a good picture in case I want
> to replicate things over here although I am pretty sure I do not have the
> same platform lying around here. Although, what platform do you have?

Yes, it's with hostapd.  With the nl80211 driver, hostapd will only add
the device to a bridge, rather than creating the bridge itself.

I'm using Debian Stretch, and my /etc/network/interfaces contains:

iface br0 inet manual
        bridge-ports eth0.nnn
        bridge-maxwait 0

iface eth0.224 inet manual

iface wlan0 inet manual
        pre-up nmcli d set wlan0 managed no
        hostapd /etc/hostapd/rmk-home.conf

and these are scripted to be brought up in the order: eth0.224, then
br0, then wlan0.

These are iMX6 Hummingboards - one is a Hummingboard2, the other is
a Hummingboard.  Both have the 4330 device on, and both are running
the same firmware.

> The timeout (-110) error can mean either firmware crashed or the sdio host
> controller went in limbo. If this happens again on 4.20 (or 5.0-rc1), you
> could build the driver with CONFIG_BRCMDBG and load the driver with
> debug=0x100010. If it is a firmware crash it should show up in the log.

Interestingly, I've just checked another Hummingboard2 running in
hostapd mode (with a 4.13 kernel) which had been up for over a year
until I recently did some maintenance on it.  It has a later firmware
and hasn't shown a problem.

brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464

so I wonder if it's just that the firmware in the Debian package
(firmware-brcm80211) is outdated.  Any ideas why distros don't
carry the 2013 firmware?

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux]

On Wed, Jan 09, 2019 at 10:56:22AM +0000, Russell King - ARM Linux wrote:
> On Wed, Jan 09, 2019 at 11:27:31AM +0100, Arend Van Spriel wrote:
> > On 1/9/2019 12:26 AM, Russell King - ARM Linux wrote:
> > >On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
> > >>Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
> > >>
> > >>>Response using Gmail on phone
> > >>
> > >>Unfortunately it had HTML and not sure if it made it to the list, so
> > >>copying your response in full below just in case. Russell, does the
> > >>commit below fix your problem?
> > >>
> > >>861cb5eb467f brcmfmac: Fix access point mode
> > >
> > > From a quick test this evening, it does seem to allow brcmfmac to work
> > >with hostapd again, which is good news.
> > >
> > >However, I've been seeing other issues with the brcmfmac over the course
> > >of the last week, which needs the brcmfmac module to be removed and
> > >re-loaded to rescue the situation - ultimately, it means that running
> > >brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
> > >patch - we will see how 4.20 with the above mentioned patch behaves over
> > >the coming week.
> > >
> > >[1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > >[1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > >[1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > >[1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > >[1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> > >[1045006.357728] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > >[1049743.889412] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > >[1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > >[1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > >[1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > >[1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> > 
> > Is this with hostapd? If so, this br0 message suggest you let hostapd create
> > a bridge, is that correct? Just trying to get a good picture in case I want
> > to replicate things over here although I am pretty sure I do not have the
> > same platform lying around here. Although, what platform do you have?
> 
> Yes, it's with hostapd.  With the nl80211 driver, hostapd will only add
> the device to a bridge, rather than creating the bridge itself.
> 
> I'm using Debian Stretch, and my /etc/network/interfaces contains:
> 
> iface br0 inet manual
>         bridge-ports eth0.nnn
>         bridge-maxwait 0
> 
> iface eth0.224 inet manual
> 
> iface wlan0 inet manual
>         pre-up nmcli d set wlan0 managed no
>         hostapd /etc/hostapd/rmk-home.conf
> 
> and these are scripted to be brought up in the order: eth0.224, then
> br0, then wlan0.
> 
> These are iMX6 Hummingboards - one is a Hummingboard2, the other is
> a Hummingboard.  Both have the 4330 device on, and both are running
> the same firmware.
> 
> > The timeout (-110) error can mean either firmware crashed or the sdio host
> > controller went in limbo. If this happens again on 4.20 (or 5.0-rc1), you
> > could build the driver with CONFIG_BRCMDBG and load the driver with
> > debug=0x100010. If it is a firmware crash it should show up in the log.
> 
> Interestingly, I've just checked another Hummingboard2 running in
> hostapd mode (with a 4.13 kernel) which had been up for over a year
> until I recently did some maintenance on it.  It has a later firmware
> and hasn't shown a problem.
> 
> brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464
> 
> so I wonder if it's just that the firmware in the Debian package
> (firmware-brcm80211) is outdated.  Any ideas why distros don't
> carry the 2013 firmware?

Okay, it's happened again - leading up to the event:

[52429.342374] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[52431.902035] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[52431.910749] brcmfmac: brcmf_cfg80211_get_station: GET STA INFO failed, -110
[64477.184237] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[72565.439122] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)

and I guess this is where things went pear shaped:

[77842.523962] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[77843.515863] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[78439.934016] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[78440.921980] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[81442.351749] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[81443.343667] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[157822.092920] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[209836.023622] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[209838.651573] brcmfmac: send_key_to_dongle: wsec_key error (-110)
[209843.515226] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
[219678.790941] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)

I'm now going to try with the later firmware:

brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/11/2019 3:15 PM, Russell King - ARM Linux wrote:
> On Wed, Jan 09, 2019 at 10:56:22AM +0000, Russell King - ARM Linux wrote:
>> On Wed, Jan 09, 2019 at 11:27:31AM +0100, Arend Van Spriel wrote:
>>> On 1/9/2019 12:26 AM, Russell King - ARM Linux wrote:
>>>> On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
>>>>> Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
>>>>>
>>>>>> Response using Gmail on phone
>>>>>
>>>>> Unfortunately it had HTML and not sure if it made it to the list, so
>>>>> copying your response in full below just in case. Russell, does the
>>>>> commit below fix your problem?
>>>>>
>>>>> 861cb5eb467f brcmfmac: Fix access point mode
>>>>
>>>>  From a quick test this evening, it does seem to allow brcmfmac to work
>>>> with hostapd again, which is good news.
>>>>
>>>> However, I've been seeing other issues with the brcmfmac over the course
>>>> of the last week, which needs the brcmfmac module to be removed and
>>>> re-loaded to rescue the situation - ultimately, it means that running
>>>> brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
>>>> patch - we will see how 4.20 with the above mentioned patch behaves over
>>>> the coming week.
>>>>
>>>> [1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>>> [1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>>> [1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>>> [1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>>> [1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
>>>> [1045006.357728] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>>> [1049743.889412] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>>> [1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>>> [1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>>>> [1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>>> [1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
>>>
>>> Is this with hostapd? If so, this br0 message suggest you let hostapd create
>>> a bridge, is that correct? Just trying to get a good picture in case I want
>>> to replicate things over here although I am pretty sure I do not have the
>>> same platform lying around here. Although, what platform do you have?
>>
>> Yes, it's with hostapd.  With the nl80211 driver, hostapd will only add
>> the device to a bridge, rather than creating the bridge itself.
>>
>> I'm using Debian Stretch, and my /etc/network/interfaces contains:
>>
>> iface br0 inet manual
>>          bridge-ports eth0.nnn
>>          bridge-maxwait 0
>>
>> iface eth0.224 inet manual
>>
>> iface wlan0 inet manual
>>          pre-up nmcli d set wlan0 managed no
>>          hostapd /etc/hostapd/rmk-home.conf
>>
>> and these are scripted to be brought up in the order: eth0.224, then
>> br0, then wlan0.
>>
>> These are iMX6 Hummingboards - one is a Hummingboard2, the other is
>> a Hummingboard.  Both have the 4330 device on, and both are running
>> the same firmware.
>>
>>> The timeout (-110) error can mean either firmware crashed or the sdio host
>>> controller went in limbo. If this happens again on 4.20 (or 5.0-rc1), you
>>> could build the driver with CONFIG_BRCMDBG and load the driver with
>>> debug=0x100010. If it is a firmware crash it should show up in the log.
>>
>> Interestingly, I've just checked another Hummingboard2 running in
>> hostapd mode (with a 4.13 kernel) which had been up for over a year
>> until I recently did some maintenance on it.  It has a later firmware
>> and hasn't shown a problem.
>>
>> brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464
>>
>> so I wonder if it's just that the firmware in the Debian package
>> (firmware-brcm80211) is outdated.  Any ideas why distros don't
>> carry the 2013 firmware?
> 
> Okay, it's happened again - leading up to the event:
> 
> [52429.342374] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> [52431.902035] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> [52431.910749] brcmfmac: brcmf_cfg80211_get_station: GET STA INFO failed, -110
> [64477.184237] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> [72565.439122] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> 
> and I guess this is where things went pear shaped:
> 
> [77842.523962] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [77843.515863] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [78439.934016] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [78440.921980] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [81442.351749] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [81443.343667] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [157822.092920] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> [209836.023622] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [209838.651573] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> [209843.515226] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> [219678.790941] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> 
> I'm now going to try with the later firmware:
> 
> brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464

Could you try the compile and load test I suggested earlier. I will try 
to replicate things over here as well.

Regards,
Arend

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/14/2019 12:49 PM, Arend Van Spriel wrote:
> On 1/11/2019 3:15 PM, Russell King - ARM Linux wrote:
>> On Wed, Jan 09, 2019 at 10:56:22AM +0000, Russell King - ARM Linux wrote:
>>> On Wed, Jan 09, 2019 at 11:27:31AM +0100, Arend Van Spriel wrote:
>>>> On 1/9/2019 12:26 AM, Russell King - ARM Linux wrote:
>>>>> On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
>>>>>> Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
>>>>>>
>>>>>>> Response using Gmail on phone
>>>>>>
>>>>>> Unfortunately it had HTML and not sure if it made it to the list, so
>>>>>> copying your response in full below just in case. Russell, does the
>>>>>> commit below fix your problem?
>>>>>>
>>>>>> 861cb5eb467f brcmfmac: Fix access point mode
>>>>>
>>>>>  From a quick test this evening, it does seem to allow brcmfmac to 
>>>>> work
>>>>> with hostapd again, which is good news.
>>>>>
>>>>> However, I've been seeing other issues with the brcmfmac over the 
>>>>> course
>>>>> of the last week, which needs the brcmfmac module to be removed and
>>>>> re-loaded to rescue the situation - ultimately, it means that running
>>>>> brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
>>>>> patch - we will see how 4.20 with the above mentioned patch behaves 
>>>>> over
>>>>> the coming week.
>>>>>
>>>>> [1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>>>>> waiting for no pending 802.1x packets
>>>>> [1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>>>>> waiting for no pending 802.1x packets
>>>>> [1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>>>>> waiting for no pending 802.1x packets
>>>>> [1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>>>>> waiting for no pending 802.1x packets
>>>>> [1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: 
>>>>> brcmf_proto_bcdc_msg failed w/status -110
>>>>> [1045006.357728] br0: received packet on wlan0 with own address as 
>>>>> source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>>>> [1049743.889412] br0: received packet on wlan0 with own address as 
>>>>> source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>>>> [1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>>>>> waiting for no pending 802.1x packets
>>>>> [1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>>>>> [1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>>>>> waiting for no pending 802.1x packets
>>>>> [1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting 
>>>>> SCB (de-)authorize failed, -110
>>>>
>>>> Is this with hostapd? If so, this br0 message suggest you let 
>>>> hostapd create
>>>> a bridge, is that correct? Just trying to get a good picture in case 
>>>> I want
>>>> to replicate things over here although I am pretty sure I do not 
>>>> have the
>>>> same platform lying around here. Although, what platform do you have?
>>>
>>> Yes, it's with hostapd.  With the nl80211 driver, hostapd will only add
>>> the device to a bridge, rather than creating the bridge itself.
>>>
>>> I'm using Debian Stretch, and my /etc/network/interfaces contains:
>>>
>>> iface br0 inet manual
>>>          bridge-ports eth0.nnn
>>>          bridge-maxwait 0
>>>
>>> iface eth0.224 inet manual
>>>
>>> iface wlan0 inet manual
>>>          pre-up nmcli d set wlan0 managed no
>>>          hostapd /etc/hostapd/rmk-home.conf
>>>
>>> and these are scripted to be brought up in the order: eth0.224, then
>>> br0, then wlan0.
>>>
>>> These are iMX6 Hummingboards - one is a Hummingboard2, the other is
>>> a Hummingboard.  Both have the 4330 device on, and both are running
>>> the same firmware.
>>>
>>>> The timeout (-110) error can mean either firmware crashed or the 
>>>> sdio host
>>>> controller went in limbo. If this happens again on 4.20 (or 
>>>> 5.0-rc1), you
>>>> could build the driver with CONFIG_BRCMDBG and load the driver with
>>>> debug=0x100010. If it is a firmware crash it should show up in the log.
>>>
>>> Interestingly, I've just checked another Hummingboard2 running in
>>> hostapd mode (with a 4.13 kernel) which had been up for over a year
>>> until I recently did some maintenance on it.  It has a later firmware
>>> and hasn't shown a problem.
>>>
>>> brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jan 23 2013 
>>> 17:47:32 version 5.90.195.114 FWID 01-f9e7e464
>>>
>>> so I wonder if it's just that the firmware in the Debian package
>>> (firmware-brcm80211) is outdated.  Any ideas why distros don't
>>> carry the 2013 firmware?
>>
>> Okay, it's happened again - leading up to the event:
>>
>> [52429.342374] brcmfmac: brcmf_proto_bcdc_query_dcmd: 
>> brcmf_proto_bcdc_msg failed w/status -110
>> [52431.902035] brcmfmac: brcmf_proto_bcdc_query_dcmd: 
>> brcmf_proto_bcdc_msg failed w/status -110
>> [52431.910749] brcmfmac: brcmf_cfg80211_get_station: GET STA INFO 
>> failed, -110
>> [64477.184237] br0: received packet on wlan0 with own address as 
>> source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>> [72565.439122] br0: received packet on wlan0 with own address as 
>> source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>
>> and I guess this is where things went pear shaped:
>>
>> [77842.523962] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [77843.515863] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [78439.934016] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [78440.921980] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [81442.351749] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [81443.343667] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [157822.092920] br0: received packet on wlan0 with own address as 
>> source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>> [209836.023622] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out 
>> waiting for no pending 802.1x packets
>> [209838.651573] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>> [209843.515226] brcmfmac: brcmf_cfg80211_del_station: 
>> SCB_DEAUTHENTICATE_FOR_REASON failed -110
>> [219678.790941] br0: received packet on wlan0 with own address as 
>> source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>
>> I'm now going to try with the later firmware:
>>
>> brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Jan 23 2013 
>> 17:47:32 version 5.90.195.114 FWID 01-f9e7e464
> 
> Could you try the compile and load test I suggested earlier. I will try 
> to replicate things over here as well.

Regarding that. Could you provide me the hostapd.conf you are using 
without any privacy sensitive stuff of course.

Regards,
Arend

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
> On 1/11/2019 3:15 PM, Russell King - ARM Linux wrote:
> > On Wed, Jan 09, 2019 at 10:56:22AM +0000, Russell King - ARM Linux wrote:
> > > On Wed, Jan 09, 2019 at 11:27:31AM +0100, Arend Van Spriel wrote:
> > > > On 1/9/2019 12:26 AM, Russell King - ARM Linux wrote:
> > > > > On Tue, Jan 08, 2019 at 06:40:46PM +0200, Kalle Valo wrote:
> > > > > > Arend Van Spriel <arend.vanspriel@broadcom.com> writes:
> > > > > > 
> > > > > > > Response using Gmail on phone
> > > > > > 
> > > > > > Unfortunately it had HTML and not sure if it made it to the list, so
> > > > > > copying your response in full below just in case. Russell, does the
> > > > > > commit below fix your problem?
> > > > > > 
> > > > > > 861cb5eb467f brcmfmac: Fix access point mode
> > > > > 
> > > > >  From a quick test this evening, it does seem to allow brcmfmac to work
> > > > > with hostapd again, which is good news.
> > > > > 
> > > > > However, I've been seeing other issues with the brcmfmac over the course
> > > > > of the last week, which needs the brcmfmac module to be removed and
> > > > > re-loaded to rescue the situation - ultimately, it means that running
> > > > > brcmfmac in host AP mode is unreliable.  This is with 4.19 and my
> > > > > patch - we will see how 4.20 with the above mentioned patch behaves over
> > > > > the coming week.
> > > > > 
> > > > > [1036107.225569] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [1036108.217519] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [1043906.813243] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [1043907.809184] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [1044220.587626] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> > > > > [1045006.357728] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > > > > [1049743.889412] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > > > > [1061305.953430] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [1061308.641378] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > > > > [1061309.665234] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [1061312.993053] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> > > > 
> > > > Is this with hostapd? If so, this br0 message suggest you let hostapd create
> > > > a bridge, is that correct? Just trying to get a good picture in case I want
> > > > to replicate things over here although I am pretty sure I do not have the
> > > > same platform lying around here. Although, what platform do you have?
> > > 
> > > Yes, it's with hostapd.  With the nl80211 driver, hostapd will only add
> > > the device to a bridge, rather than creating the bridge itself.
> > > 
> > > I'm using Debian Stretch, and my /etc/network/interfaces contains:
> > > 
> > > iface br0 inet manual
> > >          bridge-ports eth0.nnn
> > >          bridge-maxwait 0
> > > 
> > > iface eth0.224 inet manual
> > > 
> > > iface wlan0 inet manual
> > >          pre-up nmcli d set wlan0 managed no
> > >          hostapd /etc/hostapd/rmk-home.conf
> > > 
> > > and these are scripted to be brought up in the order: eth0.224, then
> > > br0, then wlan0.
> > > 
> > > These are iMX6 Hummingboards - one is a Hummingboard2, the other is
> > > a Hummingboard.  Both have the 4330 device on, and both are running
> > > the same firmware.
> > > 
> > > > The timeout (-110) error can mean either firmware crashed or the sdio host
> > > > controller went in limbo. If this happens again on 4.20 (or 5.0-rc1), you
> > > > could build the driver with CONFIG_BRCMDBG and load the driver with
> > > > debug=0x100010. If it is a firmware crash it should show up in the log.
> > > 
> > > Interestingly, I've just checked another Hummingboard2 running in
> > > hostapd mode (with a 4.13 kernel) which had been up for over a year
> > > until I recently did some maintenance on it.  It has a later firmware
> > > and hasn't shown a problem.
> > > 
> > > brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464
> > > 
> > > so I wonder if it's just that the firmware in the Debian package
> > > (firmware-brcm80211) is outdated.  Any ideas why distros don't
> > > carry the 2013 firmware?
> > 
> > Okay, it's happened again - leading up to the event:
> > 
> > [52429.342374] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> > [52431.902035] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
> > [52431.910749] brcmfmac: brcmf_cfg80211_get_station: GET STA INFO failed, -110
> > [64477.184237] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > [72565.439122] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > 
> > and I guess this is where things went pear shaped:
> > 
> > [77842.523962] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [77843.515863] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [78439.934016] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [78440.921980] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [81442.351749] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [81443.343667] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [157822.092920] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > [209836.023622] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [209838.651573] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > [209843.515226] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > [219678.790941] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > 
> > I'm now going to try with the later firmware:
> > 
> > brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Jan 23 2013 17:47:32 version 5.90.195.114 FWID 01-f9e7e464
> 
> Could you try the compile and load test I suggested earlier. I will try to
> replicate things over here as well.

This is slow progress because it seems to take a few days to
conclusively show whether there's a problem or not.  It doesn't seem
to be a case of simply boot and test for five minutes.

However, it would appear that the later firmware does indeed fix the
problem.  I'll go back to the older firmware and try what you said
today.

On Friday, I had one case where switching from the older firmware to
the newer required a reboot (to power cycle the 4330) rather than just
replacing the firmware file in /lib/firmware and reloading the module.
The symptom was hostapd was timing out the WPA authentication due to
an apparent lack of response from the STA - seemingly due to the AP
not receiving / delivering those packets.  I verified that with
hostapd in debug mode, stracing hostapd, and trying with two
different STA.

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Mon, Jan 14, 2019 at 12:59:00PM +0100, Arend Van Spriel wrote:
> On 1/14/2019 12:49 PM, Arend Van Spriel wrote:
> > Could you try the compile and load test I suggested earlier. I will try
> > to replicate things over here as well.
> 
> Regarding that. Could you provide me the hostapd.conf you are using without
> any privacy sensitive stuff of course.

Distro is Debian Stretch.

Here's the hostapd config file:

interface=wlan0
bridge=br0
driver=nl80211
ctrl_interface=/var/run/hostapd
ctrl_interface_group=0
country_code=GB
ieee80211d=0
ieee80211h=0
#local_pwr_constraint=3
#spectrum_mgmt_required=1
hw_mode=g
channel=11
auth_algs=3
ignore_broadcast_ssid=0
wmm_enabled=1
uapsd_advertisement_enabled=1
wmm_ac_bk_cwmin=4
wmm_ac_bk_cwmax=10
wmm_ac_bk_aifs=7
wmm_ac_bk_txop_limit=0
wmm_ac_bk_acm=0
wmm_ac_be_aifs=3
wmm_ac_be_cwmin=4
wmm_ac_be_cwmax=10
wmm_ac_be_txop_limit=0
wmm_ac_be_acm=0
wmm_ac_vi_aifs=2
wmm_ac_vi_cwmin=3
wmm_ac_vi_cwmax=4
wmm_ac_vi_txop_limit=94
wmm_ac_vi_acm=0
wmm_ac_vo_aifs=2
wmm_ac_vo_cwmin=2
wmm_ac_vo_cwmax=3
wmm_ac_vo_txop_limit=47
wmm_ac_vo_acm=0

#ieee80211n=1
ht_capab=[HT20][DSSS_CCK-40]

ssid=xxxxxxxx
wpa=2
wpa_passphrase=xxxxxxxx
wpa_key_mgmt=WPA-PSK
wpa_pairwise=TKIP
rsn_pairwise=CCMP


-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
> Could you try the compile and load test I suggested earlier. I will try to
> replicate things over here as well.

I'm not sure that helps:

[588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
[589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
[589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
[589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
[589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
[589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
...
[605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28

Looking at the time the messages (at 589095.542690) are produced, what
seems to cause this is when I head out with my LineageOS (TI WiLink
based) phone to the car and drive off.  I've suspected that's the case
with all the previous iterations of this problem too.

At this point, the LineageOS phone is completely unable to reassociate
with the AP, but it can see the AP with varying amounts of signal - it
shows medium signal, which drops to nothing when it tries to associate.
As soon as it stops, the indicated signal seems to come back... not
sure if that's a LineageOS thing or something that is really happening
on the Broadcom side.

It looks to me like the older firmware is not happy about a station
disappearing off into the distance... surely I can't be the only one
who takes an associated station out of range of a BRCM4330 in hostap
mode?

I don't seem to have any messages from the firmware, and I can't find
anything useful under /sys/kernel/debug for the driver - the only
thing I have is:

# tree /sys/kernel/debug/ieee80211/phy5
/sys/kernel/debug/ieee80211/phy5
├── features
├── fragmentation_threshold
├── fwcap
├── fws_stats
├── ht40allow_map
├── long_retry_limit
├── revinfo
├── rts_threshold
└── short_retry_limit

0 directories, 9 files

Also no devcoredumps appear to have been produced, although the
facility is enabled.

I'm going back to the 2013 firmware now, which seems to behave itself.

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/16/2019 1:12 AM, Russell King - ARM Linux admin wrote:
> On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
>> Could you try the compile and load test I suggested earlier. I will try to
>> replicate things over here as well.
> 
> I'm not sure that helps:
> 
> [588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
> [588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
> [588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
> [589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> [589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> [589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> [589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> [589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> [589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> [589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> [601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> [601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> [601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> ...
> [605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> [605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> [605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28

So actually it shows me that we are not getting responses. That and the 
pend8021x is starting to look pretty fishy, but lacking console messages 
may be build issue that I explain further down.

> Looking at the time the messages (at 589095.542690) are produced, what
> seems to cause this is when I head out with my LineageOS (TI WiLink
> based) phone to the car and drive off.  I've suspected that's the case
> with all the previous iterations of this problem too.
> 
> At this point, the LineageOS phone is completely unable to reassociate
> with the AP, but it can see the AP with varying amounts of signal - it
> shows medium signal, which drops to nothing when it tries to associate.
> As soon as it stops, the indicated signal seems to come back... not
> sure if that's a LineageOS thing or something that is really happening
> on the Broadcom side.
> 
> It looks to me like the older firmware is not happy about a station
> disappearing off into the distance... surely I can't be the only one
> who takes an associated station out of range of a BRCM4330 in hostap
> mode?

Thanks. Always good to have a scenario to trigger it. I tried setting it 
up over here. Everything looks fine but my stations don't see any 
beacons coming from it :-(

> I don't seem to have any messages from the firmware, and I can't find
> anything useful under /sys/kernel/debug for the driver - the only
> thing I have is:
> 
> # tree /sys/kernel/debug/ieee80211/phy5
> /sys/kernel/debug/ieee80211/phy5
> ├── features
> ├── fragmentation_threshold
> ├── fwcap
> ├── fws_stats
> ├── ht40allow_map
> ├── long_retry_limit
> ├── revinfo
> ├── rts_threshold
> └── short_retry_limit

That is weird. For SDIO it should also have three additional files:

forensics
counters
console_interval

The fact that these are absent suggests that sdio.c was not build with 
DEBUG define. How do you build the brcmfmac driver?

> 0 directories, 9 files
> 
> Also no devcoredumps appear to have been produced, although the
> facility is enabled.
> 
> I'm going back to the 2013 firmware now, which seems to behave itself.

I was also thinking about what has changed since 4.18. One commit that 
comes to mind is the rewrite of scatter-gather handling in bcmsdh.c, ie.
commit 4a5a553ddef7 ("brcmfmac: Use standard SKB list accessors in 
brcmf_sdiod_sglist_rw."). Maybe you revert that and try again.

Regards,
Arend

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Wed, Jan 16, 2019 at 01:08:21PM +0100, Arend Van Spriel wrote:
> On 1/16/2019 1:12 AM, Russell King - ARM Linux admin wrote:
> > On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
> > > Could you try the compile and load test I suggested earlier. I will try to
> > > replicate things over here as well.
> > 
> > I'm not sure that helps:
> > 
> > [588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
> > [588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
> > [588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
> > [589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > [589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > [589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > [589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > [589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> > [589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > [589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > [601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > [601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > [601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > ...
> > [605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > [605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > [605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> 
> So actually it shows me that we are not getting responses. That and the
> pend8021x is starting to look pretty fishy, but lacking console messages may
> be build issue that I explain further down.
> 
> > Looking at the time the messages (at 589095.542690) are produced, what
> > seems to cause this is when I head out with my LineageOS (TI WiLink
> > based) phone to the car and drive off.  I've suspected that's the case
> > with all the previous iterations of this problem too.
> > 
> > At this point, the LineageOS phone is completely unable to reassociate
> > with the AP, but it can see the AP with varying amounts of signal - it
> > shows medium signal, which drops to nothing when it tries to associate.
> > As soon as it stops, the indicated signal seems to come back... not
> > sure if that's a LineageOS thing or something that is really happening
> > on the Broadcom side.
> > 
> > It looks to me like the older firmware is not happy about a station
> > disappearing off into the distance... surely I can't be the only one
> > who takes an associated station out of range of a BRCM4330 in hostap
> > mode?
> 
> Thanks. Always good to have a scenario to trigger it. I tried setting it up
> over here. Everything looks fine but my stations don't see any beacons
> coming from it :-(
> 
> > I don't seem to have any messages from the firmware, and I can't find
> > anything useful under /sys/kernel/debug for the driver - the only
> > thing I have is:
> > 
> > # tree /sys/kernel/debug/ieee80211/phy5
> > /sys/kernel/debug/ieee80211/phy5
> > ├── features
> > ├── fragmentation_threshold
> > ├── fwcap
> > ├── fws_stats
> > ├── ht40allow_map
> > ├── long_retry_limit
> > ├── revinfo
> > ├── rts_threshold
> > └── short_retry_limit
> 
> That is weird. For SDIO it should also have three additional files:
> 
> forensics
> counters
> console_interval
> 
> The fact that these are absent suggests that sdio.c was not build with DEBUG
> define. How do you build the brcmfmac driver?

With a split build tree, and brcmfmac as a module.  I've just moved
drivers/net/broadcom/brcm80211 out of the way and re-built with verbose
mode enabled.  The gcc lines show that they are indeed passed -DDEBUG.

If I look inside the sdio.o object, I do find the strings:

intrcount:    %u
lastintrs:    %u
pollcnt:      %u
regfails:     %u

which are from brcmf_debugfs_sdio_count_read(), and is only built when
DEBUG is defined - so the build looks correct.  I also find this in the
module I have on the target system, so it too was indeed built with
-DDEBUG as intended.

Nope, your debugfs support can't possibly work for anyone in 4.20.

sdio.c sets up the debugfs stuff in brcmf_sdio_debugfs_create() which
wants wiphy->debugfsdir.  This is called via brcmf_bus_preinit() from
brcmf_sdio_bus_preinit().  This happens before brcmf_cfg80211_attach().

This is the key point - brcmf_cfg80211_attach() calls wiphy_register(),
which is where the wiphy's debugfs directory is setup:

        /* add to debugfs */
        rdev->wiphy.debugfsdir =
                debugfs_create_dir(wiphy_name(&rdev->wiphy),
                                   ieee80211_debugfs_dir);

Consequently, at the time when brcmf_sdio_debugfs_create() is called,
the debugfs directory has not been setup, so the function merely
returns.

> I was also thinking about what has changed since 4.18. One commit that comes
> to mind is the rewrite of scatter-gather handling in bcmsdh.c, ie.
> commit 4a5a553ddef7 ("brcmfmac: Use standard SKB list accessors in
> brcmf_sdiod_sglist_rw."). Maybe you revert that and try again.
> 
> Regards,
> Arend
> 

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/16/2019 1:51 PM, Russell King - ARM Linux admin wrote:
> On Wed, Jan 16, 2019 at 01:08:21PM +0100, Arend Van Spriel wrote:
>> On 1/16/2019 1:12 AM, Russell King - ARM Linux admin wrote:
>>> On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
>>>> Could you try the compile and load test I suggested earlier. I will try to
>>>> replicate things over here as well.
>>>
>>> I'm not sure that helps:
>>>
>>> [588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
>>> [588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
>>> [588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
>>> [589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>> [589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>>> [589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
>>> [589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>> [589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>>> [589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
>>> [589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
>>> [589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>> [601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> ...
>>> [605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>
>> So actually it shows me that we are not getting responses. That and the
>> pend8021x is starting to look pretty fishy, but lacking console messages may
>> be build issue that I explain further down.
>>
>>> Looking at the time the messages (at 589095.542690) are produced, what
>>> seems to cause this is when I head out with my LineageOS (TI WiLink
>>> based) phone to the car and drive off.  I've suspected that's the case
>>> with all the previous iterations of this problem too.
>>>
>>> At this point, the LineageOS phone is completely unable to reassociate
>>> with the AP, but it can see the AP with varying amounts of signal - it
>>> shows medium signal, which drops to nothing when it tries to associate.
>>> As soon as it stops, the indicated signal seems to come back... not
>>> sure if that's a LineageOS thing or something that is really happening
>>> on the Broadcom side.
>>>
>>> It looks to me like the older firmware is not happy about a station
>>> disappearing off into the distance... surely I can't be the only one
>>> who takes an associated station out of range of a BRCM4330 in hostap
>>> mode?
>>
>> Thanks. Always good to have a scenario to trigger it. I tried setting it up
>> over here. Everything looks fine but my stations don't see any beacons
>> coming from it :-(
>>
>>> I don't seem to have any messages from the firmware, and I can't find
>>> anything useful under /sys/kernel/debug for the driver - the only
>>> thing I have is:
>>>
>>> # tree /sys/kernel/debug/ieee80211/phy5
>>> /sys/kernel/debug/ieee80211/phy5
>>> ├── features
>>> ├── fragmentation_threshold
>>> ├── fwcap
>>> ├── fws_stats
>>> ├── ht40allow_map
>>> ├── long_retry_limit
>>> ├── revinfo
>>> ├── rts_threshold
>>> └── short_retry_limit
>>
>> That is weird. For SDIO it should also have three additional files:
>>
>> forensics
>> counters
>> console_interval
>>
>> The fact that these are absent suggests that sdio.c was not build with DEBUG
>> define. How do you build the brcmfmac driver?
> 
> With a split build tree, and brcmfmac as a module.  I've just moved
> drivers/net/broadcom/brcm80211 out of the way and re-built with verbose
> mode enabled.  The gcc lines show that they are indeed passed -DDEBUG.
> 
> If I look inside the sdio.o object, I do find the strings:
> 
> intrcount:    %u
> lastintrs:    %u
> pollcnt:      %u
> regfails:     %u
> 
> which are from brcmf_debugfs_sdio_count_read(), and is only built when
> DEBUG is defined - so the build looks correct.  I also find this in the
> module I have on the target system, so it too was indeed built with
> -DDEBUG as intended.
> 
> Nope, your debugfs support can't possibly work for anyone in 4.20.
> 
> sdio.c sets up the debugfs stuff in brcmf_sdio_debugfs_create() which
> wants wiphy->debugfsdir.  This is called via brcmf_bus_preinit() from
> brcmf_sdio_bus_preinit().  This happens before brcmf_cfg80211_attach().
> 
> This is the key point - brcmf_cfg80211_attach() calls wiphy_register(),
> which is where the wiphy's debugfs directory is setup:
> 
>          /* add to debugfs */
>          rdev->wiphy.debugfsdir =
>                  debugfs_create_dir(wiphy_name(&rdev->wiphy),
>                                     ieee80211_debugfs_dir);
> 
> Consequently, at the time when brcmf_sdio_debugfs_create() is called,
> the debugfs directory has not been setup, so the function merely
> returns.

Crap. I totally missed that when reworking the code to use the wiphy 
debugfsdir.

Thanks,
Arend

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend Van Spriel]

On 1/16/2019 1:51 PM, Russell King - ARM Linux admin wrote:
> On Wed, Jan 16, 2019 at 01:08:21PM +0100, Arend Van Spriel wrote:
>> On 1/16/2019 1:12 AM, Russell King - ARM Linux admin wrote:
>>> On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
>>>> Could you try the compile and load test I suggested earlier. I will try to
>>>> replicate things over here as well.
>>>
>>> I'm not sure that helps:
>>>
>>> [588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
>>> [588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
>>> [588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
>>> [589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>> [589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>>> [589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
>>> [589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
>>> [589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
>>> [589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
>>> [589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
>>> [589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
>>> [601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> ...
>>> [605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>> [605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
>>
>> So actually it shows me that we are not getting responses. That and the
>> pend8021x is starting to look pretty fishy, but lacking console messages may
>> be build issue that I explain further down.
>>
>>> Looking at the time the messages (at 589095.542690) are produced, what
>>> seems to cause this is when I head out with my LineageOS (TI WiLink
>>> based) phone to the car and drive off.  I've suspected that's the case
>>> with all the previous iterations of this problem too.
>>>
>>> At this point, the LineageOS phone is completely unable to reassociate
>>> with the AP, but it can see the AP with varying amounts of signal - it
>>> shows medium signal, which drops to nothing when it tries to associate.
>>> As soon as it stops, the indicated signal seems to come back... not
>>> sure if that's a LineageOS thing or something that is really happening
>>> on the Broadcom side.
>>>
>>> It looks to me like the older firmware is not happy about a station
>>> disappearing off into the distance... surely I can't be the only one
>>> who takes an associated station out of range of a BRCM4330 in hostap
>>> mode?
>>
>> Thanks. Always good to have a scenario to trigger it. I tried setting it up
>> over here. Everything looks fine but my stations don't see any beacons
>> coming from it :-(
>>
>>> I don't seem to have any messages from the firmware, and I can't find
>>> anything useful under /sys/kernel/debug for the driver - the only
>>> thing I have is:
>>>
>>> # tree /sys/kernel/debug/ieee80211/phy5
>>> /sys/kernel/debug/ieee80211/phy5
>>> ├── features
>>> ├── fragmentation_threshold
>>> ├── fwcap
>>> ├── fws_stats
>>> ├── ht40allow_map
>>> ├── long_retry_limit
>>> ├── revinfo
>>> ├── rts_threshold
>>> └── short_retry_limit
>>
>> That is weird. For SDIO it should also have three additional files:
>>
>> forensics
>> counters
>> console_interval
>>
>> The fact that these are absent suggests that sdio.c was not build with DEBUG
>> define. How do you build the brcmfmac driver?
> 
> With a split build tree, and brcmfmac as a module.  I've just moved
> drivers/net/broadcom/brcm80211 out of the way and re-built with verbose
> mode enabled.  The gcc lines show that they are indeed passed -DDEBUG.
> 
> If I look inside the sdio.o object, I do find the strings:
> 
> intrcount:    %u
> lastintrs:    %u
> pollcnt:      %u
> regfails:     %u
> 
> which are from brcmf_debugfs_sdio_count_read(), and is only built when
> DEBUG is defined - so the build looks correct.  I also find this in the
> module I have on the target system, so it too was indeed built with
> -DDEBUG as intended.
> 
> Nope, your debugfs support can't possibly work for anyone in 4.20.
> 
> sdio.c sets up the debugfs stuff in brcmf_sdio_debugfs_create() which
> wants wiphy->debugfsdir.  This is called via brcmf_bus_preinit() from
> brcmf_sdio_bus_preinit().  This happens before brcmf_cfg80211_attach().
> 
> This is the key point - brcmf_cfg80211_attach() calls wiphy_register(),
> which is where the wiphy's debugfs directory is setup:
> 
>          /* add to debugfs */
>          rdev->wiphy.debugfsdir =
>                  debugfs_create_dir(wiphy_name(&rdev->wiphy),
>                                     ieee80211_debugfs_dir);
> 
> Consequently, at the time when brcmf_sdio_debugfs_create() is called,
> the debugfs directory has not been setup, so the function merely
> returns.

The patch below works for me so can you provide the counters file 
contents after hitting the issue.

Regards,
Arend
---
diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h 
b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
index c496518..3d441c5 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
@@ -90,6 +90,7 @@ struct brcmf_bus_ops {
  	int (*get_memdump)(struct device *dev, void *data, size_t len);
  	int (*get_fwname)(struct device *dev, const char *ext,
  			  unsigned char *fw_name);
+	void (*debugfs_create)(struct device *dev);
  };


@@ -235,6 +236,15 @@ int brcmf_bus_get_fwname(struct brcmf_bus *bus, 
const char *ext,
  	return bus->ops->get_fwname(bus->dev, ext, fw_name);
  }

+static inline
+void brcmf_bus_debugfs_create(struct brcmf_bus *bus)
+{
+	if (!bus->ops->debugfs_create)
+		return;
+
+	return bus->ops->debugfs_create(bus->dev);
+}
+
  /*
   * interface functions from common layer
   */
diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c 
b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
index 7c1da1f..463754a 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
@@ -1104,6 +1104,7 @@ static int brcmf_bus_started(struct brcmf_pub 
*drvr, struct cfg80211_ops *ops)
  	brcmf_debugfs_add_entry(drvr, "revinfo", brcmf_revinfo_read);
  	brcmf_feat_debugfs_create(drvr);
  	brcmf_proto_debugfs_create(drvr);
+	brcmf_bus_debugfs_create(bus_if);

  	return 0;

diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c 
b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
index 0cd5b8d..5f9de61 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
@@ -3143,9 +3143,12 @@ static int brcmf_debugfs_sdio_count_read(struct 
seq_file *seq, void *data)
  	return 0;
  }

-static void brcmf_sdio_debugfs_create(struct brcmf_sdio *bus)
+static void brcmf_sdio_debugfs_create(struct device *dev)
  {
-	struct brcmf_pub *drvr = bus->sdiodev->bus_if->drvr;
+	struct brcmf_bus *bus_if = dev_get_drvdata(dev);
+	struct brcmf_pub *drvr = bus_if->drvr;
+	struct brcmf_sdio_dev *sdiodev = bus_if->bus_priv.sdio;
+	struct brcmf_sdio *bus = sdiodev->bus;
  	struct dentry *dentry = brcmf_debugfs_get_devdir(drvr);

  	if (IS_ERR_OR_NULL(dentry))
@@ -3165,7 +3168,7 @@ static int brcmf_sdio_checkdied(struct brcmf_sdio 
*bus)
  	return 0;
  }

-static void brcmf_sdio_debugfs_create(struct brcmf_sdio *bus)
+static void brcmf_sdio_debugfs_create(struct device *dev)
  {
  }
  #endif /* DEBUG */
@@ -3477,8 +3480,6 @@ static int brcmf_sdio_bus_preinit(struct device *dev)
  	if (bus->rxbuf)
  		bus->rxblen = value;

-	brcmf_sdio_debugfs_create(bus);
-
  	/* the commands below use the terms tx and rx from
  	 * a device perspective, ie. bus:txglom affects the
  	 * bus transfers from device to host.
@@ -4088,6 +4089,7 @@ int brcmf_sdio_get_fwname(struct device *dev, 
const char *ext, u8 *fw_name)
  	.get_ramsize = brcmf_sdio_bus_get_ramsize,
  	.get_memdump = brcmf_sdio_bus_get_memdump,
  	.get_fwname = brcmf_sdio_get_fwname,
+	.debugfs_create = brcmf_sdio_debugfs_create
  };

  #define BRCMF_SDIO_FW_CODE	0

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Wed, Jan 16, 2019 at 02:21:32PM +0100, Arend Van Spriel wrote:
> On 1/16/2019 1:51 PM, Russell King - ARM Linux admin wrote:
> > On Wed, Jan 16, 2019 at 01:08:21PM +0100, Arend Van Spriel wrote:
> > > On 1/16/2019 1:12 AM, Russell King - ARM Linux admin wrote:
> > > > On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
> > > > > Could you try the compile and load test I suggested earlier. I will try to
> > > > > replicate things over here as well.
> > > > 
> > > > I'm not sure that helps:
> > > > 
> > > > [588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
> > > > [588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
> > > > [588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
> > > > [589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > [589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > > > [589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > > > [589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > [589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > > > [589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> > > > [589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > > > [589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > [601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > > > [601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > [601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > ...
> > > > [605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > [605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > [605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > 
> > > So actually it shows me that we are not getting responses. That and the
> > > pend8021x is starting to look pretty fishy, but lacking console messages may
> > > be build issue that I explain further down.
> > > 
> > > > Looking at the time the messages (at 589095.542690) are produced, what
> > > > seems to cause this is when I head out with my LineageOS (TI WiLink
> > > > based) phone to the car and drive off.  I've suspected that's the case
> > > > with all the previous iterations of this problem too.
> > > > 
> > > > At this point, the LineageOS phone is completely unable to reassociate
> > > > with the AP, but it can see the AP with varying amounts of signal - it
> > > > shows medium signal, which drops to nothing when it tries to associate.
> > > > As soon as it stops, the indicated signal seems to come back... not
> > > > sure if that's a LineageOS thing or something that is really happening
> > > > on the Broadcom side.
> > > > 
> > > > It looks to me like the older firmware is not happy about a station
> > > > disappearing off into the distance... surely I can't be the only one
> > > > who takes an associated station out of range of a BRCM4330 in hostap
> > > > mode?
> > > 
> > > Thanks. Always good to have a scenario to trigger it. I tried setting it up
> > > over here. Everything looks fine but my stations don't see any beacons
> > > coming from it :-(
> > > 
> > > > I don't seem to have any messages from the firmware, and I can't find
> > > > anything useful under /sys/kernel/debug for the driver - the only
> > > > thing I have is:
> > > > 
> > > > # tree /sys/kernel/debug/ieee80211/phy5
> > > > /sys/kernel/debug/ieee80211/phy5
> > > > ├── features
> > > > ├── fragmentation_threshold
> > > > ├── fwcap
> > > > ├── fws_stats
> > > > ├── ht40allow_map
> > > > ├── long_retry_limit
> > > > ├── revinfo
> > > > ├── rts_threshold
> > > > └── short_retry_limit
> > > 
> > > That is weird. For SDIO it should also have three additional files:
> > > 
> > > forensics
> > > counters
> > > console_interval
> > > 
> > > The fact that these are absent suggests that sdio.c was not build with DEBUG
> > > define. How do you build the brcmfmac driver?
> > 
> > With a split build tree, and brcmfmac as a module.  I've just moved
> > drivers/net/broadcom/brcm80211 out of the way and re-built with verbose
> > mode enabled.  The gcc lines show that they are indeed passed -DDEBUG.
> > 
> > If I look inside the sdio.o object, I do find the strings:
> > 
> > intrcount:    %u
> > lastintrs:    %u
> > pollcnt:      %u
> > regfails:     %u
> > 
> > which are from brcmf_debugfs_sdio_count_read(), and is only built when
> > DEBUG is defined - so the build looks correct.  I also find this in the
> > module I have on the target system, so it too was indeed built with
> > -DDEBUG as intended.
> > 
> > Nope, your debugfs support can't possibly work for anyone in 4.20.
> > 
> > sdio.c sets up the debugfs stuff in brcmf_sdio_debugfs_create() which
> > wants wiphy->debugfsdir.  This is called via brcmf_bus_preinit() from
> > brcmf_sdio_bus_preinit().  This happens before brcmf_cfg80211_attach().
> > 
> > This is the key point - brcmf_cfg80211_attach() calls wiphy_register(),
> > which is where the wiphy's debugfs directory is setup:
> > 
> >          /* add to debugfs */
> >          rdev->wiphy.debugfsdir =
> >                  debugfs_create_dir(wiphy_name(&rdev->wiphy),
> >                                     ieee80211_debugfs_dir);
> > 
> > Consequently, at the time when brcmf_sdio_debugfs_create() is called,
> > the debugfs directory has not been setup, so the function merely
> > returns.
> 
> The patch below works for me so can you provide the counters file contents
> after hitting the issue.

Thanks, it'll probably be a couple of days before I can get anything -
no time to rebuild the kernel today.

> 
> Regards,
> Arend
> ---
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> index c496518..3d441c5 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> @@ -90,6 +90,7 @@ struct brcmf_bus_ops {
>  	int (*get_memdump)(struct device *dev, void *data, size_t len);
>  	int (*get_fwname)(struct device *dev, const char *ext,
>  			  unsigned char *fw_name);
> +	void (*debugfs_create)(struct device *dev);
>  };
> 
> 
> @@ -235,6 +236,15 @@ int brcmf_bus_get_fwname(struct brcmf_bus *bus, const
> char *ext,
>  	return bus->ops->get_fwname(bus->dev, ext, fw_name);
>  }
> 
> +static inline
> +void brcmf_bus_debugfs_create(struct brcmf_bus *bus)
> +{
> +	if (!bus->ops->debugfs_create)
> +		return;
> +
> +	return bus->ops->debugfs_create(bus->dev);
> +}
> +
>  /*
>   * interface functions from common layer
>   */
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> index 7c1da1f..463754a 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> @@ -1104,6 +1104,7 @@ static int brcmf_bus_started(struct brcmf_pub *drvr,
> struct cfg80211_ops *ops)
>  	brcmf_debugfs_add_entry(drvr, "revinfo", brcmf_revinfo_read);
>  	brcmf_feat_debugfs_create(drvr);
>  	brcmf_proto_debugfs_create(drvr);
> +	brcmf_bus_debugfs_create(bus_if);
> 
>  	return 0;
> 
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> index 0cd5b8d..5f9de61 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> @@ -3143,9 +3143,12 @@ static int brcmf_debugfs_sdio_count_read(struct
> seq_file *seq, void *data)
>  	return 0;
>  }
> 
> -static void brcmf_sdio_debugfs_create(struct brcmf_sdio *bus)
> +static void brcmf_sdio_debugfs_create(struct device *dev)
>  {
> -	struct brcmf_pub *drvr = bus->sdiodev->bus_if->drvr;
> +	struct brcmf_bus *bus_if = dev_get_drvdata(dev);
> +	struct brcmf_pub *drvr = bus_if->drvr;
> +	struct brcmf_sdio_dev *sdiodev = bus_if->bus_priv.sdio;
> +	struct brcmf_sdio *bus = sdiodev->bus;
>  	struct dentry *dentry = brcmf_debugfs_get_devdir(drvr);
> 
>  	if (IS_ERR_OR_NULL(dentry))
> @@ -3165,7 +3168,7 @@ static int brcmf_sdio_checkdied(struct brcmf_sdio
> *bus)
>  	return 0;
>  }
> 
> -static void brcmf_sdio_debugfs_create(struct brcmf_sdio *bus)
> +static void brcmf_sdio_debugfs_create(struct device *dev)
>  {
>  }
>  #endif /* DEBUG */
> @@ -3477,8 +3480,6 @@ static int brcmf_sdio_bus_preinit(struct device *dev)
>  	if (bus->rxbuf)
>  		bus->rxblen = value;
> 
> -	brcmf_sdio_debugfs_create(bus);
> -
>  	/* the commands below use the terms tx and rx from
>  	 * a device perspective, ie. bus:txglom affects the
>  	 * bus transfers from device to host.
> @@ -4088,6 +4089,7 @@ int brcmf_sdio_get_fwname(struct device *dev, const
> char *ext, u8 *fw_name)
>  	.get_ramsize = brcmf_sdio_bus_get_ramsize,
>  	.get_memdump = brcmf_sdio_bus_get_memdump,
>  	.get_fwname = brcmf_sdio_get_fwname,
> +	.debugfs_create = brcmf_sdio_debugfs_create
>  };
> 
>  #define BRCMF_SDIO_FW_CODE	0
> 

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Wed, Jan 16, 2019 at 01:56:43PM +0000, Russell King - ARM Linux admin wrote:
> On Wed, Jan 16, 2019 at 02:21:32PM +0100, Arend Van Spriel wrote:
> > On 1/16/2019 1:51 PM, Russell King - ARM Linux admin wrote:
> > > On Wed, Jan 16, 2019 at 01:08:21PM +0100, Arend Van Spriel wrote:
> > > > On 1/16/2019 1:12 AM, Russell King - ARM Linux admin wrote:
> > > > > On Mon, Jan 14, 2019 at 12:49:09PM +0100, Arend Van Spriel wrote:
> > > > > > Could you try the compile and load test I suggested earlier. I will try to
> > > > > > replicate things over here as well.
> > > > > 
> > > > > I'm not sure that helps:
> > > > > 
> > > > > [588980.874745] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
> > > > > [588980.875776] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
> > > > > [588980.876925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
> > > > > [589095.542690] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [589098.262719] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > > > > [589100.822465] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > > > > [589101.814313] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
> > > > > [589104.410194] brcmfmac: send_key_to_dongle: wsec_key error (-110)
> > > > > [589106.970045] brcmfmac: brcmf_cfg80211_change_station: Setting SCB (de-)authorize failed, -110
> > > > > [589109.530191] brcmfmac: brcmf_cfg80211_del_station: SCB_DEAUTHENTICATE_FOR_REASON failed -110
> > > > > [589110.322685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > > [601235.163954] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
> > > > > [601245.240024] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > > [601264.207886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > > ...
> > > > > [605377.238304] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > > [605395.118751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > > [605412.976951] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
> > > > 
> > > > So actually it shows me that we are not getting responses. That and the
> > > > pend8021x is starting to look pretty fishy, but lacking console messages may
> > > > be build issue that I explain further down.
> > > > 
> > > > > Looking at the time the messages (at 589095.542690) are produced, what
> > > > > seems to cause this is when I head out with my LineageOS (TI WiLink
> > > > > based) phone to the car and drive off.  I've suspected that's the case
> > > > > with all the previous iterations of this problem too.
> > > > > 
> > > > > At this point, the LineageOS phone is completely unable to reassociate
> > > > > with the AP, but it can see the AP with varying amounts of signal - it
> > > > > shows medium signal, which drops to nothing when it tries to associate.
> > > > > As soon as it stops, the indicated signal seems to come back... not
> > > > > sure if that's a LineageOS thing or something that is really happening
> > > > > on the Broadcom side.
> > > > > 
> > > > > It looks to me like the older firmware is not happy about a station
> > > > > disappearing off into the distance... surely I can't be the only one
> > > > > who takes an associated station out of range of a BRCM4330 in hostap
> > > > > mode?
> > > > 
> > > > Thanks. Always good to have a scenario to trigger it. I tried setting it up
> > > > over here. Everything looks fine but my stations don't see any beacons
> > > > coming from it :-(
> > > > 
> > > > > I don't seem to have any messages from the firmware, and I can't find
> > > > > anything useful under /sys/kernel/debug for the driver - the only
> > > > > thing I have is:
> > > > > 
> > > > > # tree /sys/kernel/debug/ieee80211/phy5
> > > > > /sys/kernel/debug/ieee80211/phy5
> > > > > ├── features
> > > > > ├── fragmentation_threshold
> > > > > ├── fwcap
> > > > > ├── fws_stats
> > > > > ├── ht40allow_map
> > > > > ├── long_retry_limit
> > > > > ├── revinfo
> > > > > ├── rts_threshold
> > > > > └── short_retry_limit
> > > > 
> > > > That is weird. For SDIO it should also have three additional files:
> > > > 
> > > > forensics
> > > > counters
> > > > console_interval
> > > > 
> > > > The fact that these are absent suggests that sdio.c was not build with DEBUG
> > > > define. How do you build the brcmfmac driver?
> > > 
> > > With a split build tree, and brcmfmac as a module.  I've just moved
> > > drivers/net/broadcom/brcm80211 out of the way and re-built with verbose
> > > mode enabled.  The gcc lines show that they are indeed passed -DDEBUG.
> > > 
> > > If I look inside the sdio.o object, I do find the strings:
> > > 
> > > intrcount:    %u
> > > lastintrs:    %u
> > > pollcnt:      %u
> > > regfails:     %u
> > > 
> > > which are from brcmf_debugfs_sdio_count_read(), and is only built when
> > > DEBUG is defined - so the build looks correct.  I also find this in the
> > > module I have on the target system, so it too was indeed built with
> > > -DDEBUG as intended.
> > > 
> > > Nope, your debugfs support can't possibly work for anyone in 4.20.
> > > 
> > > sdio.c sets up the debugfs stuff in brcmf_sdio_debugfs_create() which
> > > wants wiphy->debugfsdir.  This is called via brcmf_bus_preinit() from
> > > brcmf_sdio_bus_preinit().  This happens before brcmf_cfg80211_attach().
> > > 
> > > This is the key point - brcmf_cfg80211_attach() calls wiphy_register(),
> > > which is where the wiphy's debugfs directory is setup:
> > > 
> > >          /* add to debugfs */
> > >          rdev->wiphy.debugfsdir =
> > >                  debugfs_create_dir(wiphy_name(&rdev->wiphy),
> > >                                     ieee80211_debugfs_dir);
> > > 
> > > Consequently, at the time when brcmf_sdio_debugfs_create() is called,
> > > the debugfs directory has not been setup, so the function merely
> > > returns.
> > 
> > The patch below works for me so can you provide the counters file contents
> > after hitting the issue.
> 
> Thanks, it'll probably be a couple of days before I can get anything -
> no time to rebuild the kernel today.

Hmm, also the patch can't be easily applied:

Content-Type: text/plain; charset=utf-8; format=flowed
                                         ^^^^^^^^^^^^^
basically is an excuse for email programs to break patches when
inserted inline in the email body, by wrapping and changing the
number of space characters at the start of lines.  It's fixable by
the recipient if they are prepared to manually edit almost every
line of the patch and run the result through patch --dry-run a
few times until it applies...

Maybe send patches as plain text attachments?

> > 
> > Regards,
> > Arend
> > ---
> > diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> > b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> > index c496518..3d441c5 100644
> > --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> > +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/bus.h
> > @@ -90,6 +90,7 @@ struct brcmf_bus_ops {
> >  	int (*get_memdump)(struct device *dev, void *data, size_t len);
> >  	int (*get_fwname)(struct device *dev, const char *ext,
> >  			  unsigned char *fw_name);
> > +	void (*debugfs_create)(struct device *dev);
> >  };
> > 
> > 
> > @@ -235,6 +236,15 @@ int brcmf_bus_get_fwname(struct brcmf_bus *bus, const
> > char *ext,
> >  	return bus->ops->get_fwname(bus->dev, ext, fw_name);
> >  }
> > 
> > +static inline
> > +void brcmf_bus_debugfs_create(struct brcmf_bus *bus)
> > +{
> > +	if (!bus->ops->debugfs_create)
> > +		return;
> > +
> > +	return bus->ops->debugfs_create(bus->dev);
> > +}
> > +
> >  /*
> >   * interface functions from common layer
> >   */
> > diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> > b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> > index 7c1da1f..463754a 100644
> > --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> > +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> > @@ -1104,6 +1104,7 @@ static int brcmf_bus_started(struct brcmf_pub *drvr,
> > struct cfg80211_ops *ops)
> >  	brcmf_debugfs_add_entry(drvr, "revinfo", brcmf_revinfo_read);
> >  	brcmf_feat_debugfs_create(drvr);
> >  	brcmf_proto_debugfs_create(drvr);
> > +	brcmf_bus_debugfs_create(bus_if);
> > 
> >  	return 0;
> > 
> > diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> > b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> > index 0cd5b8d..5f9de61 100644
> > --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> > +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/sdio.c
> > @@ -3143,9 +3143,12 @@ static int brcmf_debugfs_sdio_count_read(struct
> > seq_file *seq, void *data)
> >  	return 0;
> >  }
> > 
> > -static void brcmf_sdio_debugfs_create(struct brcmf_sdio *bus)
> > +static void brcmf_sdio_debugfs_create(struct device *dev)
> >  {
> > -	struct brcmf_pub *drvr = bus->sdiodev->bus_if->drvr;
> > +	struct brcmf_bus *bus_if = dev_get_drvdata(dev);
> > +	struct brcmf_pub *drvr = bus_if->drvr;
> > +	struct brcmf_sdio_dev *sdiodev = bus_if->bus_priv.sdio;
> > +	struct brcmf_sdio *bus = sdiodev->bus;
> >  	struct dentry *dentry = brcmf_debugfs_get_devdir(drvr);
> > 
> >  	if (IS_ERR_OR_NULL(dentry))
> > @@ -3165,7 +3168,7 @@ static int brcmf_sdio_checkdied(struct brcmf_sdio
> > *bus)
> >  	return 0;
> >  }
> > 
> > -static void brcmf_sdio_debugfs_create(struct brcmf_sdio *bus)
> > +static void brcmf_sdio_debugfs_create(struct device *dev)
> >  {
> >  }
> >  #endif /* DEBUG */
> > @@ -3477,8 +3480,6 @@ static int brcmf_sdio_bus_preinit(struct device *dev)
> >  	if (bus->rxbuf)
> >  		bus->rxblen = value;
> > 
> > -	brcmf_sdio_debugfs_create(bus);
> > -
> >  	/* the commands below use the terms tx and rx from
> >  	 * a device perspective, ie. bus:txglom affects the
> >  	 * bus transfers from device to host.
> > @@ -4088,6 +4089,7 @@ int brcmf_sdio_get_fwname(struct device *dev, const
> > char *ext, u8 *fw_name)
> >  	.get_ramsize = brcmf_sdio_bus_get_ramsize,
> >  	.get_memdump = brcmf_sdio_bus_get_memdump,
> >  	.get_fwname = brcmf_sdio_get_fwname,
> > +	.debugfs_create = brcmf_sdio_debugfs_create
> >  };
> > 
> >  #define BRCMF_SDIO_FW_CODE	0
> > 
> 
> -- 
> RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
> FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
> According to speedtest.net: 11.9Mbps down 500kbps up

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Kalle Valo]

Arend Van Spriel <arend.vanspriel@broadcom.com> writes:

> I should have known better and used git-send-email. I will resend it
> later tonight.

BTW, this was again sent using HTML :) In case Russell filters out HTML
mails I'll act as a messenger.

-- 
Kalle Valo

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Wed, Jan 16, 2019 at 02:21:32PM +0100, Arend Van Spriel wrote:
> The patch below works for me so can you provide the counters file contents
> after hitting the issue.

Okay, with the patch fixed, it seems to have failed last night for some
reason... I'm not sure exactly when it died, possibly about an hour
after bringing it up.  Here's the full log.

[674188.169386] brcmfmac: F1 signature read @0x18000000=0x16044330
[674188.192244] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4330-sdio for chip BCM4330/4
[674188.531614] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 31 expected 31
[674188.532876] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 31 expected 31
[674188.534489] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 36 expected 36
[674188.535340] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 84 expected 84
[674188.535606] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4330-sdio for chip BCM4330/4
[674188.544601] brcmfmac mmc0:0001:1: Direct firmware load for brcm/brcmfmac4330-sdio.clm_blob failed with error -2
[674188.555155] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[674188.568076] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 276 expected 276
[674188.568139] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4330/4 wl0: Oct 25 2011 19:34:12 version 5.90.125.104
[674188.579811] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 279 expected 279
[674188.580606] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
[674188.581407] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.582207] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 45 expected 45
[674188.583033] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 45 expected 45
[674188.583931] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674188.584654] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674188.585535] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674188.586539] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 788 expected 788
[674188.587620] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 48 expected 48
[674188.588526] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
[674188.589478] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 30 expected 30
[674188.590347] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 32 expected 32
[674188.591239] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
[674188.592167] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 36 expected 36
[674188.592893] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[674188.593754] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674188.594476] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[674188.597599] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 36 expected 36
[674188.599126] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[674188.600055] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674188.600955] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674188.601729] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 32 expected 32
[674188.602519] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[674188.609345] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 1562 expected 1562
[674188.610594] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.611494] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.612337] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.613093] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.613902] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.614692] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.615691] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.617340] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.618146] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.618986] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.619906] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.620704] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.621555] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.622407] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.623174] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.624069] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.624824] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 34 expected 34
[674188.625752] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674188.626512] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 32 expected 32
[674188.627322] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 45 expected 45
[674188.628271] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 45 expected 45
[674188.630655] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674188.643691] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674188.652041] brcmfmac: CONSOLE: 
[674188.652056] brcmfmac: CONSOLE: RTE (USB-SDIO-CDC) 5.90.125.104 on BCM4330 r4 @ 37.4/80.0/80.0MHz
[674188.652066] brcmfmac: CONSOLE: sdpcmdcdc0: Broadcom SDPCMD CDC driver
[674188.652074] brcmfmac: CONSOLE: using p2p microcode
[674188.652083] brcmfmac: CONSOLE: reclaim section 0: Returned 35840 bytes to the heap
[674188.652092] brcmfmac: CONSOLE: wl0: Broadcom BCM4330 802.11 Wireless Controller 5.90.125.104
[674188.652099] brcmfmac: CONSOLE: TCAM: 64 used: 2 exceed:1
[674188.652108] brcmfmac: CONSOLE: reclaim section 1: Returned 53969 bytes to the heap
[674188.652116] brcmfmac: CONSOLE: sdpcmd_dpc: Enable
[674189.489923] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.490870] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.493574] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.495150] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.498398] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.579784] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.584426] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.585174] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.585920] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.586720] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.587548] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 32 expected 32
[674189.588639] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.589538] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
[674189.590332] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
[674189.591479] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.592930] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.593836] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.596863] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 37 expected 37
[674189.597778] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.599847] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[674189.606219] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.608057] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.609263] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.610376] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.611772] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 43 expected 43
[674189.612751] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.613604] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.614626] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.615852] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.616981] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.619829] br0: port 2(wlan0) entered blocking state
[674189.625163] br0: port 2(wlan0) entered disabled state
[674189.631653] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 43 expected 43
[674189.632428] device wlan0 entered promiscuous mode
[674189.637858] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.638894] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.640134] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.641239] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.642256] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.643597] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 43 expected 43
[674189.644631] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.645397] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.646346] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.647252] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.648207] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.655886] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[674189.667957] brcmfmac: CONSOLE: wl0: bc/mc deauth_reason on STA BSS?
[674189.727732] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.728995] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
[674189.729967] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.730894] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.731900] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.733193] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 36 expected 36
[674189.734079] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.735139] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.736663] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.737396] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.738115] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.743790] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.744667] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.745375] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.746121] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.746916] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.763862] brcmfmac: CONSOLE: 2 packets not freed at wlc_down
[674189.826446] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.829309] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 68 expected 68
[674189.829978] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[674189.837884] br0: port 2(wlan0) entered blocking state
[674189.843192] br0: port 2(wlan0) entered forwarding state
[674189.851206] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[674189.852241] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.853249] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 32 expected 32
[674189.854248] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.855255] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674189.862109] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 49 expected 49
[674189.863114] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674189.865226] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674189.866229] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674189.867161] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674189.870911] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674190.942585] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 49 expected 49
[674190.943757] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
[674190.944682] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
[674190.945739] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
[674190.947201] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
[674190.949043] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674224.997894] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[674225.001821] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[674225.002556] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674225.003276] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674225.004170] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674225.053950] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674225.062091] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[674225.062991] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[674225.077856] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 0
[674231.261377] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 789 expected 789
[674241.468933] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[674524.994041] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[674524.995691] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[674524.996906] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[674789.949598] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[674789.950312] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674789.951026] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674789.951938] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[674807.989875] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[674807.990785] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[674807.991795] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[675097.982242] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[675097.983180] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[675097.984451] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[675131.782331] brcmfmac: CONSOLE: wl0: ampdu_resp_timeout: cleaning up resp tid 0 waiting for seq 0x59c for 200 ms
[675348.979377] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[675348.980387] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[675348.981844] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[675390.876779] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[675390.877640] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[675390.878505] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[675390.879567] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[675390.895704] brcmfmac: CONSOLE: wl0: ampdu_resp_timeout: cleaning up resp tid 0 waiting for seq 0x5aa for 200 ms
[675652.966709] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[675652.967540] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[675652.968715] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[675965.956290] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[675965.957127] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[675965.958261] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[675990.849698] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[675990.850412] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[675990.851132] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[675990.852062] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[675990.865568] brcmfmac: CONSOLE: wl0: ampdu_resp_timeout: cleaning up resp tid 0 waiting for seq 0x5b7 for 200 ms
[676125.101860] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 4
[676269.950898] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[676269.951744] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[676269.952754] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[676466.826476] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[676466.826492] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[676472.074194] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[676472.074210] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[676496.704756] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus_regmpdu: unexpected completion: seq 0x15, start seq 0x0
[676496.704771] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x16, start seq 0x0
[676496.704781] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x17, start seq 0x0
[676496.704792] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x18, start seq 0x0
[676496.704801] brcmfmac: CONSOLE: wl0: unexpected seq: start_seq 0x0, seq 0x19
[676561.289093] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x2c tid 4
[676561.289108] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x620 tid 0
[676562.938207] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[676562.939115] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[676562.940173] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[676589.958015] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[676589.958815] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[676589.959664] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[676589.960595] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[676869.932921] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[676869.933826] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[676869.934894] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[676937.491750] brcmfmac: CONSOLE: wl0: ampdu_resp_timeout: cleaning up resp tid 0 waiting for seq 0x793 for 200 ms
[677154.851453] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 5
[677168.923773] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[677168.924582] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[677168.925703] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[677189.706821] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[677189.707632] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677189.708473] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677189.709489] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677484.910905] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[677484.911724] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[677484.912959] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[677520.866571] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[677520.866586] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[677525.462346] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[677525.462362] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[677542.107174] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[677542.108360] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[677542.109310] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[677543.657272] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[677643.499536] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[677643.551676] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677643.559409] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[677643.560429] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[677643.575761] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 0
[677647.507459] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 4
[677658.658777] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[677789.644606] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[677789.645528] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677789.646415] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677789.647544] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677828.753246] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[677828.753262] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[677828.753274] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[677828.753300] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[677942.114506] brcmfmac: CONSOLE: 
[677942.114521] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114530] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114538] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114546] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114555] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114563] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114571] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114580] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114588] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114596] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114605] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114613] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114621] brcmfmac: CONSOLE: wl0: PHYTX error
[677942.114628] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.118551] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.118565] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.118574] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.118582] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.485878] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[677943.487845] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[677943.489736] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[677943.506676] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506689] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506698] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506707] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506714] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506722] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506730] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506738] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506746] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506753] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506761] brcmfmac: CONSOLE: wl0: PHYTX error
[677943.506768] brcmfmac: CONSOLE: wl0: PHYTX error
[677959.699504] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[677959.700760] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[677959.701921] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[677977.845822] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[677977.896968] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[677977.905760] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[677977.906808] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[677977.920768] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 0
[677980.104519] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 4
[678009.646914] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[678066.543757] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[678090.242278] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[678162.298239] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[678162.298254] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[678166.945914] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[678166.945930] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[678199.436108] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus_regmpdu: unexpected completion: seq 0x12, start seq 0x0
[678199.436125] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x13, start seq 0x0
[678199.436135] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x14, start seq 0x0
[678199.436145] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x15, start seq 0x0
[678199.436155] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus_regmpdu: unexpected completion: seq 0x16, start seq 0x0
[678199.436163] brcmfmac: CONSOLE: wl0: unexpected seq: start_seq 0x0, seq 0x17
[678230.330311] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x2b tid 4
[678277.832947] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[678277.833940] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[678277.835273] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[678277.847714] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x14c tid 0
[678367.746514] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[678367.746529] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[678372.374251] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[678372.374266] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[678392.801126] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus_regmpdu: unexpected completion: seq 0x2b, start seq 0x0
[678392.801142] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x2c, start seq 0x0
[678392.801153] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x2d, start seq 0x0
[678392.801163] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x2e, start seq 0x0
[678392.801191] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x2f, start seq 0x0
[678393.054261] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[678393.055118] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678393.056234] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678393.057964] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678518.497980] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x56 tid 4
[678518.497995] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x170 tid 0
[678566.824578] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[678566.825656] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[678566.826976] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[678612.164613] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[678612.164628] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[678617.588372] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[678617.588388] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[678617.588399] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus_regmpdu: unexpected completion: seq 0x56, start seq 0x0
[678617.588410] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x57, start seq 0x0
[678617.588420] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x58, start seq 0x0
[678617.588429] brcmfmac: CONSOLE: wl0: unexpected seq: start_seq 0x0, seq 0x59
[678617.588437] brcmfmac: CONSOLE: wl0: unexpected seq: start_seq 0x0, seq 0x5a
[678617.960260] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x173 tid 0
[678683.308609] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x64 tid 4
[678756.108459] brcmfmac: CONSOLE: wl0: ampdu_resp_timeout: cleaning up resp tid 0 waiting for seq 0xaf1 for 200 ms
[678757.588371] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[678757.588387] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[678757.588398] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[678757.588407] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[678763.796827] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[678763.798124] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[678763.799137] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[678763.812057] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 0 reason 36
[678763.812071] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 4 initiator 0 reason 36
[678765.631910] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[678765.631924] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[678765.631934] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[678797.976674] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[678798.005905] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 0
[678798.013165] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678798.022154] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[678798.023041] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[678800.214078] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 4
[678814.301181] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[678870.077977] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[678982.135603] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[678982.135618] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[678987.939274] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[678987.939290] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[678994.470468] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[678994.481337] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[678994.482168] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678994.483811] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678994.484747] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[678994.485583] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[678995.462429] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[678995.473127] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[678995.475241] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[678995.476425] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[678997.204426] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[678997.205502] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[678997.218840] brcmfmac: CONSOLE: wl0: wlc_deauth_sendcomplete: Failed 
[679000.034649] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[679088.058606] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[679088.096689] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
[679088.111311] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
[679088.112389] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[679088.125733] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x2 tid 0
[679090.197414] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x1 tid 4
[679103.736670] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[679158.737641] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[679262.059750] brcmfmac: CONSOLE: wl0: wlc_ampdu_recv_delba: AMPDU OFF: tid 0 initiator 1 reason 39
[679271.439179] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[679271.439195] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[679277.202872] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[679277.202887] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[679290.670105] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus_regmpdu: unexpected completion: seq 0x10, start seq 0x0
[679290.670121] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x11, start seq 0x0
[679290.670132] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x12, start seq 0x0
[679290.670141] brcmfmac: CONSOLE: wl0: ampdu_dotxstatus: unexpected completion: seq 0x13, start seq 0x0
[679340.159392] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x18 tid 4
[679345.427077] brcmfmac: CONSOLE: wl0: wlc_send_bar: seq 0x21a tid 0
[679388.046184] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 286 expected 286
[679388.047045] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 281 expected 281
[679388.048254] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 2064 expected 2064
[679587.037310] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 4 due to no progress for 2 secs
[679587.037325] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 4 initiator 1 reason 39
[679594.436407] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[679597.060430] brcmfmac: send_key_to_dongle: wsec_key error (-110)
[679597.080552] brcmfmac: CONSOLE: wl0: ampdu_watchdog: cleaning up ini tid 0 due to no progress for 2 secs
[679597.080567] brcmfmac: CONSOLE: wl0: wlc_ampdu_send_delba: tid 0 initiator 1 reason 39
[679598.022611] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[679598.980107] brcmfmac: brcmf_netdev_wait_pend8021x: Timed out waiting for no pending 802.1x packets
[679601.667976] brcmfmac: send_key_to_dongle: wsec_key error (-110)
[679602.905381] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[679602.907116] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 22 expected 22
[679602.909065] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[679613.839752] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[679613.839767] brcmfmac: CONSOLE: wl0: wlc_ampdu_dotxstatus: scb is null
[679658.183171] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[679707.001572] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[679755.702746] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[679804.476149] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[679853.246025] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[680192.739578] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[680241.511279] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[680264.135556] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[686381.516088] br0: received packet on wlan0 with own address as source address (addr:6c:ad:f8:05:0d:81, vlan:0)
[686391.583197] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[686408.128386] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[686423.253366] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[686438.198398] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689528.778375] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689546.513189] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689564.300786] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689582.079264] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689599.869496] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689910.809173] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689928.565159] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689951.110787] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689968.909630] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[689986.680260] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690004.531559] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690022.328834] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690333.479694] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690351.164860] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690369.000673] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690386.806691] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690404.593000] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690715.572437] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690733.220200] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690751.018363] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690768.780739] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[690786.632099] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691097.510170] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691115.316866] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691133.105072] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691150.898478] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691168.710485] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691486.628026] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691504.384314] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691522.173066] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691539.984338] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691557.827559] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691868.824310] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691886.503760] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691904.321375] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691922.114367] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[691939.892000] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692251.856616] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692269.205126] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692288.985144] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692306.776002] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692324.546797] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692642.471114] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692660.306637] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692678.112309] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692695.914593] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[692713.720360] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693028.551425] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693046.298834] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693064.144381] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693081.955496] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693099.727677] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693410.330714] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693428.145093] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693445.930758] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693463.829403] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693481.632481] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693799.244606] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693817.035243] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693834.798151] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693849.578429] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[693864.289318] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694175.112674] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694192.908637] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694210.652359] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694228.469818] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694246.236946] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694557.237803] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694575.003543] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694592.783406] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694610.603029] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694628.385468] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694944.082735] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694961.958048] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694979.746380] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[694997.558167] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695015.338464] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695326.139030] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695343.924484] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695361.720915] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695379.493736] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695397.329329] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695708.073930] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695725.885533] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695743.666052] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695761.548784] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[695779.305280] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696093.410044] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696111.159924] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696128.952391] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696146.730482] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696164.595375] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696475.394824] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696493.135980] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696510.924993] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696528.798791] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696546.518669] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696857.288618] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696875.073934] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696892.878010] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696910.653111] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[696928.480411] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[697246.293623] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[697264.105089] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[697281.932548] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[697299.627405] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[697317.501733] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698508.649136] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698526.173188] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698552.600283] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698570.380637] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698588.129810] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698899.846177] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698917.218855] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698935.030577] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698952.787384] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[698970.570049] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699281.493090] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699299.304678] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699314.048574] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699331.857824] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699346.607946] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699736.873108] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699754.645702] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699772.481025] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699790.246199] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[699808.044651] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700118.842189] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700136.638516] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700154.449595] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700172.206717] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700189.981664] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700500.639340] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700518.396572] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700536.208394] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700554.004122] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700571.769185] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700882.540678] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700900.333749] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700918.223971] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700936.773526] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[700954.600303] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701265.304138] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701285.092568] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701302.920098] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701317.731902] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701335.483550] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701646.377305] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701664.186887] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701681.967586] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701699.763666] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[701717.577380] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702028.359603] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702046.174637] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702061.717903] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702079.514495] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702097.271214] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702415.251714] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702432.963182] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702450.780815] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702465.550805] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702483.287798] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702794.033228] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702811.798144] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702829.619974] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702847.400696] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[702865.234319] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703176.096915] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703193.848280] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703211.649628] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703229.431352] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703247.250230] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703564.901377] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703582.682709] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703600.472643] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703618.313200] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703636.057001] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703946.784257] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703964.543780] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[703982.324665] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704000.149923] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704017.954489] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704328.848233] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704346.536867] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704364.356577] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704382.126601] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704399.993705] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704717.652953] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704735.425929] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704753.222402] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704771.004000] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[704788.743695] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705099.618647] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705117.457612] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705135.206791] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705153.018170] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705170.838645] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705481.716278] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705499.537738] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705517.316552] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705535.057593] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705552.824874] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705870.716386] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705888.457607] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705906.257070] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705924.068683] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[705941.854421] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706252.818485] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706270.630263] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706288.413798] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706306.183847] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706323.981956] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706634.935519] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706652.703629] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706670.497166] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706688.348556] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[706706.116453] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707020.920264] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707038.709797] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707056.505111] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707074.317142] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707092.113108] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707403.014599] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707420.802601] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707438.583442] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707456.411707] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707474.207883] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707785.046409] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707802.844701] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707820.680420] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707838.481873] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[707856.285545] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708174.010381] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708191.827618] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708209.553186] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708227.294674] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708245.100799] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708556.093790] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708573.764825] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708591.531054] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708607.506225] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[708625.242009] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[709366.233146] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[709384.029470] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[709401.755309] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[709416.520987] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[709434.295617] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[710894.143288] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[710911.945279] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[710929.735292] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[710947.508609] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[710965.341179] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711276.219576] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711293.976641] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711308.788612] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711330.858731] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711348.662311] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711659.513034] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711677.323794] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711695.087764] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711712.905431] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[711730.662362] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[712041.487519] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[712059.391047] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[712077.225923] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[712094.298148] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713294.228893] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713604.801114] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713622.571603] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713637.336685] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713652.031033] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713669.806408] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713980.651330] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[713998.463012] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714016.251252] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714034.055935] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714053.807172] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714364.661837] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714382.432028] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714400.230338] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714418.078899] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714434.835879] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714752.377932] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714772.134997] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714789.939469] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714809.704255] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[714827.470788] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715138.245689] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715156.043620] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715173.783136] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715191.563445] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715209.375650] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715520.120654] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715537.895819] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715555.745301] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715573.550681] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715591.297532] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715908.998022] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715926.752786] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715944.533684] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715962.353597] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[715980.102473] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716292.778792] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716310.550686] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716328.346516] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716346.152706] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716363.938717] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716674.670957] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716692.441716] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716710.198691] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716728.002763] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[716745.778514] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717063.584286] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717081.340363] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717099.154134] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717116.950318] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717134.697734] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717445.366669] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717463.144447] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717480.964787] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717498.628135] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717516.666332] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717827.333875] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717845.194557] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717862.974759] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717880.794963] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[717898.590981] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718216.349865] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718234.137654] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718251.926195] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718269.716891] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718287.505610] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718598.420279] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718616.301785] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718634.067094] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718651.967397] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718669.636110] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718980.483719] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[718998.219799] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719016.005392] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719033.809251] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719051.605701] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719350.711708] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719369.397339] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719387.169682] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719405.028832] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719422.833395] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719440.613479] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719751.420871] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719769.217263] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719786.990355] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719804.794267] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[719821.709306] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720132.389891] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720150.163227] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720167.927835] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720185.731717] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720203.512258] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720514.539053] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720532.131540] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720549.975131] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720563.959872] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[720581.715912] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[721758.967540] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[721776.652860] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[721794.487529] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[721812.270319] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[721830.072235] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722141.058641] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722158.496551] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722176.262925] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722194.034440] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722211.808976] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722522.530114] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722540.194269] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722557.998673] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722575.800550] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722593.575217] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722904.295048] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722922.015214] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722939.832956] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722957.615096] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[722975.387845] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723292.961477] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723310.778764] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723328.553311] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723346.378609] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723364.130342] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723674.885708] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723692.661873] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723710.481389] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723728.292872] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[723746.058532] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724060.648573] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724078.419421] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724096.225527] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724113.988649] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724131.761225] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724449.311067] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724467.107470] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724484.895482] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724502.733269] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724520.505828] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724832.241634] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724850.031520] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724867.880008] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724885.693730] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[724903.487496] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725215.438769] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725233.125400] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725250.953006] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725268.834897] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725286.623376] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725597.787924] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725615.578847] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725633.380792] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725651.129852] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725668.980014] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725980.921271] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[725998.696330] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726016.513185] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726034.349514] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726052.160108] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726363.831285] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726381.624045] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726399.443439] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726417.341141] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726435.084918] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726746.150306] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726763.980141] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726781.781793] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726799.614532] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[726817.404464] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727129.328924] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727147.171758] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727165.000090] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727182.803396] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727200.637625] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727512.594059] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727530.377432] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727548.186494] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727566.021549] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
[727583.810015] brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28


-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Russell King - ARM Linux admin]

On Fri, Jan 18, 2019 at 09:36:17PM +0100, Arend van Spriel wrote:
> On 1/17/2019 11:03 AM, Russell King - ARM Linux admin wrote:> On Wed, Jan 16, 2019 at 02:21:32PM +0100, Arend Van Spriel wrote:
> >> The patch below works for me so can you provide the counters file contents
> >> after hitting the issue.
> > 
> > Okay, with the patch fixed, it seems to have failed last night for some
> > reason... I'm not sure exactly when it died, possibly about an hour
> > after bringing it up.  Here's the full log.
> 
> Sorry for the somewhat late response. I wanted to discuss the log with
> firmware engineer. Can you tell how many stations were connected to this
> AP before and/or when it died? What does "died" mean? From the log I can
> only conclude the firmware is not crashing. So I assume by "died" you
> mean no data is successfully exchanged between hostapd and stations. This
> is probably due to the failing send_key_to_dongle. Could you try the patch
> below to be sure about the key configuration that fails.

By "died" I mean that I've seen several things happen - not always
all of them:

1) the signal perceived by my phone has reduced to a very low level
   (like almost nothing) despite the AP being in direct line of sight
   in the same room, whereas normally it would be showing full signal.

2) the phone (and other devices) will not associate with the AP.
   They go through the initial authentication fine but fail to
   complete the WPA authentication.

Looking at hostapd's debug log, hostapd is aware of the station
attempting to authenticate.  For example, I've observed the following
from hostapd in debug mode:

wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: associated
wlan0: STA xx:xx:xx:xx:xx:xx WPA: event 1 notification
wlan0: STA xx:xx:xx:xx:xx:xx WPA: start authentication
wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: unauthorizing port
wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake
wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake
wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake
wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake
wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
wlan0: STA xx:xx:xx:xx:xx:xx WPA: PTKSTART: Retry limit 4 reached
wlan0: STA xx:xx:xx:xx:xx:xx WPA: event 3 notification
wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: unauthorizing port
wlan0: STA xx:xx:xx:xx:xx:xx MLME: MLME-DEAUTHENTICATE.indication(xx:xx:xx:xx:xx:xx
wlan0: STA xx:xx:xx:xx:xx:xx MLME: MLME-DELETEKEYS.request(xx:xx:xx:xx:xx:xx)
wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: disassociated
wlan0: STA xx:xx:xx:xx:xx:xx WPA: event 2 notification
wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: unauthorizing port

and that repeats.

I picked those out of a strace of hostapd I did on January 11.  Here's
the strace beween the EAPOL stuff:

13663 write(1, "wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout\n", 52) = 52
13663 write(1, "wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake\n", 69) = 69
13663 sendto(11, "<removed>", 99, 0, {sa_family=AF_PACKET, proto=0x888e, if14, pkttype=PACKET_HOST, addr(6)={0, 6069441db3a9}, 20) = 99
13663 clock_gettime(CLOCK_BOOTTIME, {244522, 12768606}) = 0
13663 clock_gettime(CLOCK_BOOTTIME, {244522, 13615672}) = 0
13663 _newselect(16, [4 6 8 9 10 12 13 14 15], [], [], {0, 999153}) = 0 (Timeout)
13663 clock_gettime(CLOCK_BOOTTIME, {244523, 16399625}) = 0
13663 write(1, "wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout\n", 52) = 52
13663 write(1, "wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake\n", 69) = 69

Hostapd is not getting a response to its 4-way handshake.

I'll try the patch out at some point during the next few days - and
I hope that doesn't result in lots of log spam.

> 
> Regards,
> Arend
> ---
>  drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
> index a62c48d..d43d4c0 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
> @@ -460,6 +460,8 @@ static void convert_key_from_CPU(struct brcmf_wsec_key *key,
>  	int err;
>  	struct brcmf_wsec_key_le key_le;
>  
> +	brcmf_err("idx %d algo %d flags %x\n",
> +		  key->index, key->algo, key->flags);
>  	convert_key_from_CPU(key, &key_le);
>  
>  	brcmf_netdev_wait_pend8021x(ifp);
> -- 
> 1.9.1
> 
> 

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line in suburbia: sync at 12.1Mbps down 622kbps up
According to speedtest.net: 11.9Mbps down 500kbps up

Re: [REGRESSION] hostapd 2.4..2.7 broken with 4.18+

[Arend van Spriel]

On 1/17/2019 11:03 AM, Russell King - ARM Linux admin wrote:> On Wed, Jan 16, 2019 at 02:21:32PM +0100, Arend Van Spriel wrote:
>> The patch below works for me so can you provide the counters file contents
>> after hitting the issue.
> 
> Okay, with the patch fixed, it seems to have failed last night for some
> reason... I'm not sure exactly when it died, possibly about an hour
> after bringing it up.  Here's the full log.

Sorry for the somewhat late response. I wanted to discuss the log with
firmware engineer. Can you tell how many stations were connected to this
AP before and/or when it died? What does "died" mean? From the log I can
only conclude the firmware is not crashing. So I assume by "died" you
mean no data is successfully exchanged between hostapd and stations. This
is probably due to the failing send_key_to_dongle. Could you try the patch
below to be sure about the key configuration that fails.

Regards,
Arend
---
 drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
index a62c48d..d43d4c0 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
@@ -460,6 +460,8 @@ static void convert_key_from_CPU(struct brcmf_wsec_key *key,
 	int err;
 	struct brcmf_wsec_key_le key_le;
 
+	brcmf_err("idx %d algo %d flags %x\n",
+		  key->index, key->algo, key->flags);
 	convert_key_from_CPU(key, &key_le);
 
 	brcmf_netdev_wait_pend8021x(ifp);
-- 
1.9.1