diff mbox

[resend] brcmfmac: p2p and normal ap access are not always possible at the same time

Message ID 20170526105747.16874-2-hdegoede@redhat.com (mailing list archive)
State Rejected
Delegated to: Kalle Valo
Headers show

Commit Message

Hans de Goede May 26, 2017, 10:57 a.m. UTC
The firmware responding with -EBUSY when trying to add an extra virtual-if
is a normal thing, do not print an error for this.

Signed-off-by: Hans de Goede <hdegoede@redhat.com>
---
 .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14 ++++++++++----
 drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
 2 files changed, 14 insertions(+), 5 deletions(-)

Comments

Kalle Valo June 13, 2017, 5:58 a.m. UTC | #1
Hans de Goede <hdegoede@redhat.com> wrote:

> The firmware responding with -EBUSY when trying to add an extra virtual-if
> is a normal thing, do not print an error for this.
> 
> Signed-off-by: Hans de Goede <hdegoede@redhat.com>

Arend, what should I do with this patch? Take it?
Arend Van Spriel Aug. 4, 2017, 12:35 p.m. UTC | #2
On 5/26/2017 12:57 PM, Hans de Goede wrote:
> The firmware responding with -EBUSY when trying to add an extra virtual-if
> is a normal thing, do not print an error for this.

Hi Hans,

First of all, sorry! This one is long overdue (thanks for the reminder, 
Kalle). Not sure what the claim is here. I have to check the firmware to 
see what could make this fail. Thing is that wpa_supplicant will try to 
create the interface upon startup and it is really required for P2P 
operations. Now people not using that will probably not care about the 
failure, but I would like to find out why it is failing. wpa_supplicant 
will not do a retry upon -EBUSY.

With which firmware (target string and version) are you seeing this so I 
know where to dive in.

Regards,
Arend

> Signed-off-by: Hans de Goede <hdegoede@redhat.com>
> ---
>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14 ++++++++++----
>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
>   2 files changed, 14 insertions(+), 5 deletions(-)
>
Hans de Goede Aug. 30, 2017, 10:24 a.m. UTC | #3
Hi Arend,

Sorry I was a bit slow to respond to this.

On 04-08-17 14:35, Arend van Spriel wrote:
> On 5/26/2017 12:57 PM, Hans de Goede wrote:
>> The firmware responding with -EBUSY when trying to add an extra virtual-if
>> is a normal thing, do not print an error for this.
> 
> Hi Hans,
> 
> First of all, sorry! This one is long overdue (thanks for the reminder, Kalle). Not sure what the claim is here. I have to check the firmware to see what could make this fail. Thing is that wpa_supplicant will try to create the interface upon startup and it is really required for P2P operations. Now people not using that will probably not care about the failure, but I would like to find out why it is failing. wpa_supplicant will not do a retry upon -EBUSY.
> 
> With which firmware (target string and version) are you seeing this so I know where to dive in.

[root@localhost ~]# dmesg | grep brcm
[   11.252078] brcmutil: loading out-of-tree module taints kernel.
[   11.252159] brcmutil: module verification failed: signature and/or required key missing - tainting kernel
[   11.484195] brcmfmac: brcmf_sdio_probe: Loading firmware brcm/brcmfmac43430a0-sdio.bin for chip 0000a9a6 rev 00000000
[   11.484290] usbcore: registered new interface driver brcmfmac
[   11.616053] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jun  6 2014 14:50:39 version 7.10.226.49 (r) FWID 01-8962686a
[   14.782464] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
[   14.782488] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-16
[   34.300531] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
[   34.300549] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-16

[root@localhost ~]# strings /lib/firmware/brcm/brcmfmac43430a0-sdio.bin | tail -n 1
43430a0-roml/sdio-g-pool-p2p-pno-pktfilter-keepalive-aoe-mchan-proptxstatus-lpc-wl11u-rcc-fmc-wepso-ccx-okc-fbt-noccxaka-txpwr-ampduhostreorder-clm_43xx_lg Version: 7.10.226.49 CRC: bf92cb0b Date: Fri 2014-06-06 14:55:15 KST FWID 01-8962686a

Regards,

Hans
Hans de Goede Aug. 30, 2017, 10:30 a.m. UTC | #4
Hi,

On 30-08-17 12:24, Hans de Goede wrote:
> Hi Arend,
> 
> Sorry I was a bit slow to respond to this.
> 
> On 04-08-17 14:35, Arend van Spriel wrote:
>> On 5/26/2017 12:57 PM, Hans de Goede wrote:
>>> The firmware responding with -EBUSY when trying to add an extra virtual-if
>>> is a normal thing, do not print an error for this.
>>
>> Hi Hans,
>>
>> First of all, sorry! This one is long overdue (thanks for the reminder, Kalle). Not sure what the claim is here. I have to check the firmware to see what could make this fail. Thing is that wpa_supplicant will try to create the interface upon startup and it is really required for P2P operations. Now people not using that will probably not care about the failure, but I would like to find out why it is failing. wpa_supplicant will not do a retry upon -EBUSY.
>>
>> With which firmware (target string and version) are you seeing this so I know where to dive in.
> 
> [root@localhost ~]# dmesg | grep brcm
> [   11.252078] brcmutil: loading out-of-tree module taints kernel.
> [   11.252159] brcmutil: module verification failed: signature and/or required key missing - tainting kernel
> [   11.484195] brcmfmac: brcmf_sdio_probe: Loading firmware brcm/brcmfmac43430a0-sdio.bin for chip 0000a9a6 rev 00000000
> [   11.484290] usbcore: registered new interface driver brcmfmac
> [   11.616053] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jun  6 2014 14:50:39 version 7.10.226.49 (r) FWID 01-8962686a
> [   14.782464] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
> [   14.782488] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-16
> [   34.300531] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
> [   34.300549] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-16
> 
> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac43430a0-sdio.bin | tail -n 1
> 43430a0-roml/sdio-g-pool-p2p-pno-pktfilter-keepalive-aoe-mchan-proptxstatus-lpc-wl11u-rcc-fmc-wepso-ccx-okc-fbt-noccxaka-txpwr-ampduhostreorder-clm_43xx_lg Version: 7.10.226.49 CRC: bf92cb0b Date: Fri 2014-06-06 14:55:15 KST FWID 01-8962686a

Since that firmware is quite old, I've tried again with a newer version:

[   11.219863] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jul  1 2016 18:02:40 version 7.10.1 (A0 Station/P2P feature) FWID 01-bae8afee

[root@localhost ~]# strings /lib/firmware/brcm/brcmfmac43430a0-sdio.bin | tail -n 1
43430a0-roml/sdio-g-pool-p2p-pno-pktfilter-keepalive-aoe-mchan-proptxstatus-lpc-wl11u-rcc-fmc-wepso-ccx-okc-fbt-noccxaka-txpwr-ampduhostreorder-clm_43xx_lg-ndoe Version: 7.10.1.244 CRC: 73c82137 Date: Fri 2016-07-01 18:03:15 KST Ucode Ver: 940.1020 FWID: 01-bae8afee

Which still results in the same errors.

Note this is with the a0 revision of the 43430 for which a firmware file is
still missing from linux-firmware. If you happen to be able to add a file
to linux-firmware while looking into this, that would be great.

Regards,

Hans
Hans de Goede Oct. 19, 2017, 11:20 a.m. UTC | #5
Hi,

On 30-08-17 12:30, Hans de Goede wrote:
> Hi,
> 
> On 30-08-17 12:24, Hans de Goede wrote:
>> Hi Arend,
>>
>> Sorry I was a bit slow to respond to this.
>>
>> On 04-08-17 14:35, Arend van Spriel wrote:
>>> On 5/26/2017 12:57 PM, Hans de Goede wrote:
>>>> The firmware responding with -EBUSY when trying to add an extra virtual-if
>>>> is a normal thing, do not print an error for this.
>>>
>>> Hi Hans,
>>>
>>> First of all, sorry! This one is long overdue (thanks for the reminder, Kalle). Not sure what the claim is here. I have to check the firmware to see what could make this fail. Thing is that wpa_supplicant will try to create the interface upon startup and it is really required for P2P operations. Now people not using that will probably not care about the failure, but I would like to find out why it is failing. wpa_supplicant will not do a retry upon -EBUSY.
>>>
>>> With which firmware (target string and version) are you seeing this so I know where to dive in.
>>
>> [root@localhost ~]# dmesg | grep brcm
>> [   11.252078] brcmutil: loading out-of-tree module taints kernel.
>> [   11.252159] brcmutil: module verification failed: signature and/or required key missing - tainting kernel
>> [   11.484195] brcmfmac: brcmf_sdio_probe: Loading firmware brcm/brcmfmac43430a0-sdio.bin for chip 0000a9a6 rev 00000000
>> [   11.484290] usbcore: registered new interface driver brcmfmac
>> [   11.616053] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jun  6 2014 14:50:39 version 7.10.226.49 (r) FWID 01-8962686a
>> [   14.782464] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
>> [   14.782488] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-16
>> [   34.300531] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
>> [   34.300549] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlan0 type 10 failed: err=-16
>>
>> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac43430a0-sdio.bin | tail -n 1
>> 43430a0-roml/sdio-g-pool-p2p-pno-pktfilter-keepalive-aoe-mchan-proptxstatus-lpc-wl11u-rcc-fmc-wepso-ccx-okc-fbt-noccxaka-txpwr-ampduhostreorder-clm_43xx_lg Version: 7.10.226.49 CRC: bf92cb0b Date: Fri 2014-06-06 14:55:15 KST FWID 01-8962686a
> 
> Since that firmware is quite old, I've tried again with a newer version:
> 
> [   11.219863] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jul  1 2016 18:02:40 version 7.10.1 (A0 Station/P2P feature) FWID 01-bae8afee
> 
> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac43430a0-sdio.bin | tail -n 1
> 43430a0-roml/sdio-g-pool-p2p-pno-pktfilter-keepalive-aoe-mchan-proptxstatus-lpc-wl11u-rcc-fmc-wepso-ccx-okc-fbt-noccxaka-txpwr-ampduhostreorder-clm_43xx_lg-ndoe Version: 7.10.1.244 CRC: 73c82137 Date: Fri 2016-07-01 18:03:15 KST Ucode Ver: 940.1020 FWID: 01-bae8afee
> 
> Which still results in the same errors.
> 
> Note this is with the a0 revision of the 43430 for which a firmware file is
> still missing from linux-firmware. If you happen to be able to add a file
> to linux-firmware while looking into this, that would be great.

Any update on this ?  Since this does not seem to be going anywhere,
can we at least merge the harmless patch silencing the errors ?

Regards,

Hans
Hans de Goede Feb. 25, 2018, 2:52 p.m. UTC | #6
Hi,

On 26-05-17 12:57, Hans de Goede wrote:
> The firmware responding with -EBUSY when trying to add an extra virtual-if
> is a normal thing, do not print an error for this.
> 
> Signed-off-by: Hans de Goede <hdegoede@redhat.com>

I'm now seeing this on another device too, but this time the error
thrown is -EBADE, this seems to be new with recent kernels:

[root@localhost ~]# dmesg | grep brcmfmac
[   34.265950] usbcore: registered new interface driver brcmfmac
[   34.266059] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
[   34.376468] brcmfmac: brcmf_fw_map_chip_to_name: using brcm/brcmfmac4356-pcie.bin for chip 0x004356(17238) rev 0x000002
[   34.855143] brcmfmac 0000:01:00.0: Direct firmware load for brcm/brcmfmac4356-pcie.clm_blob failed with error -2
[   34.855147] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available(err=-2), device may have limited channels available
[   34.857029] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jun  4 2017 16:50:07 version 7.35.101.6 (r702795) FWID 01-5e8eb735
[   34.938854] brcmfmac 0000:01:00.0 wlp1s0: renamed from wlan0
[   37.086420] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
[   37.086431] brcmfmac: brcmf_cfg80211_add_iface: add iface p2p-dev-wlp1s0 type 10 failed: err=-52

[root@localhost ~]# strings /lib/firmware/brcm/brcmfmac4356-pcie.bin | tail -n 1
4356a2-roml/pcie-ag-msgbuf-splitrx-p2p-pno-aoe-pktfilter-keepalive-sr-mchan-pktctx-proptxstatus-ampduhostreorder-lpc-pwropt-txbf-wl11u-mfp-tdls-amsdutx-sarctrl-proxd-hs20sta-rcc-wepso-ndoe-linkstat-gscan-hchk-logtrace-roamexp-rmon Version: 7.35.101.6 (r702795) CRC: 4f3f65c5 Date: Sun 2017-06-04 16:51:38 PDT Ucode Ver: 963.316 FWID: 01-5e8eb735

It would be good if we can silence these errors, or maybe at a
minimum lower their log-level from error to warning?

Regards,

Hans


> ---
>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14 ++++++++++----
>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
>   2 files changed, 14 insertions(+), 5 deletions(-)
> 
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
> index cd1d6730eab7..dae88f3d041d 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
> @@ -684,11 +684,17 @@ static struct wireless_dev *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
>   		return ERR_PTR(-EINVAL);
>   	}
>   
> -	if (IS_ERR(wdev))
> -		brcmf_err("add iface %s type %d failed: err=%d\n",
> -			  name, type, (int)PTR_ERR(wdev));
> -	else
> +	if (IS_ERR(wdev)) {
> +		err = PTR_ERR(wdev);
> +		if (err != -EBUSY)
> +			brcmf_err("add iface %s type %d failed: err=%d\n",
> +				  name, type, err);
> +		else
> +			brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
> +				  name, type, err);
> +	} else {
>   		brcmf_cfg80211_update_proto_addr_mode(wdev);
> +	}
>   
>   	return wdev;
>   }
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
> index aa299c47bfa2..1bb296ffb46f 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
> @@ -2090,7 +2090,10 @@ static struct wireless_dev *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
>   	/* Initialize P2P Discovery in the firmware */
>   	err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
>   	if (err < 0) {
> -		brcmf_err("set p2p_disc error\n");
> +		if (err != -EBUSY)
> +			brcmf_err("set p2p_disc error\n");
> +		else
> +			brcmf_dbg(INFO, "set p2p_disc error\n");
>   		brcmf_fweh_p2pdev_setup(pri_ifp, false);
>   		brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
>   		goto fail;
>
Arend Van Spriel Feb. 26, 2018, 10:22 a.m. UTC | #7
On 2/25/2018 3:52 PM, Hans de Goede wrote:
> Hi,
>
> On 26-05-17 12:57, Hans de Goede wrote:
>> The firmware responding with -EBUSY when trying to add an extra
>> virtual-if
>> is a normal thing, do not print an error for this.
>>
>> Signed-off-by: Hans de Goede <hdegoede@redhat.com>
>
> I'm now seeing this on another device too, but this time the error
> thrown is -EBADE, this seems to be new with recent kernels:

Yup. Before we were passing firmware errors up to user-space, which was 
confusing and potentially be misinterpreted. However, looking at the 
output below it would have been good to log the firmware error as well. 
And staring at it some more I suddenly realize I broke the feature 
detection module with this change. Actually only the GSCAN feature 
detection.

> [root@localhost ~]# dmesg | grep brcmfmac
> [   34.265950] usbcore: registered new interface driver brcmfmac
> [   34.266059] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
> [   34.376468] brcmfmac: brcmf_fw_map_chip_to_name: using
> brcm/brcmfmac4356-pcie.bin for chip 0x004356(17238) rev 0x000002
> [   34.855143] brcmfmac 0000:01:00.0: Direct firmware load for
> brcm/brcmfmac4356-pcie.clm_blob failed with error -2
> [   34.855147] brcmfmac: brcmf_c_process_clm_blob: no clm_blob
> available(err=-2), device may have limited channels available
> [   34.857029] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0:
> Jun  4 2017 16:50:07 version 7.35.101.6 (r702795) FWID 01-5e8eb735
> [   34.938854] brcmfmac 0000:01:00.0 wlp1s0: renamed from wlan0
> [   37.086420] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
> [   37.086431] brcmfmac: brcmf_cfg80211_add_iface: add iface
> p2p-dev-wlp1s0 type 10 failed: err=-52
>
> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac4356-pcie.bin |
> tail -n 1
> 4356a2-roml/pcie-ag-msgbuf-splitrx-p2p-pno-aoe-pktfilter-keepalive-sr-mchan-pktctx-proptxstatus-ampduhostreorder-lpc-pwropt-txbf-wl11u-mfp-tdls-amsdutx-sarctrl-proxd-hs20sta-rcc-wepso-ndoe-linkstat-gscan-hchk-logtrace-roamexp-rmon
> Version: 7.35.101.6 (r702795) CRC: 4f3f65c5 Date: Sun 2017-06-04
> 16:51:38 PDT Ucode Ver: 963.316 FWID: 01-5e8eb735
>
> It would be good if we can silence these errors, or maybe at a
> minimum lower their log-level from error to warning?

I had a look at it and it seems to be a difference in firmware api that 
we need to support in the driver. Need to do a bit more digging, but it 
seems an actual issue. You could silence it for now, but I prefer to 
wait for the fix.

Regards,
Arend

> Regards,
>
> Hans
>
>
>> ---
>>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14
>> ++++++++++----
>>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
>>   2 files changed, 14 insertions(+), 5 deletions(-)
>>
>> diff --git
>> a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>> index cd1d6730eab7..dae88f3d041d 100644
>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>> @@ -684,11 +684,17 @@ static struct wireless_dev
>> *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
>>           return ERR_PTR(-EINVAL);
>>       }
>> -    if (IS_ERR(wdev))
>> -        brcmf_err("add iface %s type %d failed: err=%d\n",
>> -              name, type, (int)PTR_ERR(wdev));
>> -    else
>> +    if (IS_ERR(wdev)) {
>> +        err = PTR_ERR(wdev);
>> +        if (err != -EBUSY)
>> +            brcmf_err("add iface %s type %d failed: err=%d\n",
>> +                  name, type, err);
>> +        else
>> +            brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
>> +                  name, type, err);
>> +    } else {
>>           brcmf_cfg80211_update_proto_addr_mode(wdev);
>> +    }
>>       return wdev;
>>   }
>> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>> index aa299c47bfa2..1bb296ffb46f 100644
>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>> @@ -2090,7 +2090,10 @@ static struct wireless_dev
>> *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
>>       /* Initialize P2P Discovery in the firmware */
>>       err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
>>       if (err < 0) {
>> -        brcmf_err("set p2p_disc error\n");
>> +        if (err != -EBUSY)
>> +            brcmf_err("set p2p_disc error\n");
>> +        else
>> +            brcmf_dbg(INFO, "set p2p_disc error\n");
>>           brcmf_fweh_p2pdev_setup(pri_ifp, false);
>>           brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
>>           goto fail;
>>
Hans de Goede Feb. 26, 2018, 10:29 a.m. UTC | #8
Hi,

On 26-02-18 11:22, Arend van Spriel wrote:
> On 2/25/2018 3:52 PM, Hans de Goede wrote:
>> Hi,
>>
>> On 26-05-17 12:57, Hans de Goede wrote:
>>> The firmware responding with -EBUSY when trying to add an extra
>>> virtual-if
>>> is a normal thing, do not print an error for this.
>>>
>>> Signed-off-by: Hans de Goede <hdegoede@redhat.com>
>>
>> I'm now seeing this on another device too, but this time the error
>> thrown is -EBADE, this seems to be new with recent kernels:
> 
> Yup. Before we were passing firmware errors up to user-space, which was confusing and potentially be misinterpreted. However, looking at the output below it would have been good to log the firmware error as well. And staring at it some more I suddenly realize I broke the feature detection module with this change. Actually only the GSCAN feature detection.
> 
>> [root@localhost ~]# dmesg | grep brcmfmac
>> [   34.265950] usbcore: registered new interface driver brcmfmac
>> [   34.266059] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
>> [   34.376468] brcmfmac: brcmf_fw_map_chip_to_name: using
>> brcm/brcmfmac4356-pcie.bin for chip 0x004356(17238) rev 0x000002
>> [   34.855143] brcmfmac 0000:01:00.0: Direct firmware load for
>> brcm/brcmfmac4356-pcie.clm_blob failed with error -2
>> [   34.855147] brcmfmac: brcmf_c_process_clm_blob: no clm_blob
>> available(err=-2), device may have limited channels available
>> [   34.857029] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0:
>> Jun  4 2017 16:50:07 version 7.35.101.6 (r702795) FWID 01-5e8eb735
>> [   34.938854] brcmfmac 0000:01:00.0 wlp1s0: renamed from wlan0
>> [   37.086420] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
>> [   37.086431] brcmfmac: brcmf_cfg80211_add_iface: add iface
>> p2p-dev-wlp1s0 type 10 failed: err=-52
>>
>> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac4356-pcie.bin |
>> tail -n 1
>> 4356a2-roml/pcie-ag-msgbuf-splitrx-p2p-pno-aoe-pktfilter-keepalive-sr-mchan-pktctx-proptxstatus-ampduhostreorder-lpc-pwropt-txbf-wl11u-mfp-tdls-amsdutx-sarctrl-proxd-hs20sta-rcc-wepso-ndoe-linkstat-gscan-hchk-logtrace-roamexp-rmon
>> Version: 7.35.101.6 (r702795) CRC: 4f3f65c5 Date: Sun 2017-06-04
>> 16:51:38 PDT Ucode Ver: 963.316 FWID: 01-5e8eb735
>>
>> It would be good if we can silence these errors, or maybe at a
>> minimum lower their log-level from error to warning?
> 
> I had a look at it and it seems to be a difference in firmware api that we need to support in the driver. Need to do a bit more digging, but it seems an actual issue. You could silence it for now, but I prefer to wait for the fix.

Ok, what is the ETA of a fix for this?

Regards,

Hans




>>> ---
>>>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14
>>> ++++++++++----
>>>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
>>>   2 files changed, 14 insertions(+), 5 deletions(-)
>>>
>>> diff --git
>>> a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>> index cd1d6730eab7..dae88f3d041d 100644
>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>> @@ -684,11 +684,17 @@ static struct wireless_dev
>>> *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
>>>           return ERR_PTR(-EINVAL);
>>>       }
>>> -    if (IS_ERR(wdev))
>>> -        brcmf_err("add iface %s type %d failed: err=%d\n",
>>> -              name, type, (int)PTR_ERR(wdev));
>>> -    else
>>> +    if (IS_ERR(wdev)) {
>>> +        err = PTR_ERR(wdev);
>>> +        if (err != -EBUSY)
>>> +            brcmf_err("add iface %s type %d failed: err=%d\n",
>>> +                  name, type, err);
>>> +        else
>>> +            brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
>>> +                  name, type, err);
>>> +    } else {
>>>           brcmf_cfg80211_update_proto_addr_mode(wdev);
>>> +    }
>>>       return wdev;
>>>   }
>>> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>> index aa299c47bfa2..1bb296ffb46f 100644
>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>> @@ -2090,7 +2090,10 @@ static struct wireless_dev
>>> *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
>>>       /* Initialize P2P Discovery in the firmware */
>>>       err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
>>>       if (err < 0) {
>>> -        brcmf_err("set p2p_disc error\n");
>>> +        if (err != -EBUSY)
>>> +            brcmf_err("set p2p_disc error\n");
>>> +        else
>>> +            brcmf_dbg(INFO, "set p2p_disc error\n");
>>>           brcmf_fweh_p2pdev_setup(pri_ifp, false);
>>>           brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
>>>           goto fail;
>>>
>
Arend Van Spriel Feb. 26, 2018, 11:01 a.m. UTC | #9
On 2/26/2018 11:29 AM, Hans de Goede wrote:
> Hi,
>
> On 26-02-18 11:22, Arend van Spriel wrote:
>> On 2/25/2018 3:52 PM, Hans de Goede wrote:
>>> Hi,
>>>
>>> On 26-05-17 12:57, Hans de Goede wrote:
>>>> The firmware responding with -EBUSY when trying to add an extra
>>>> virtual-if
>>>> is a normal thing, do not print an error for this.
>>>>
>>>> Signed-off-by: Hans de Goede <hdegoede@redhat.com>
>>>
>>> I'm now seeing this on another device too, but this time the error
>>> thrown is -EBADE, this seems to be new with recent kernels:
>>
>> Yup. Before we were passing firmware errors up to user-space, which
>> was confusing and potentially be misinterpreted. However, looking at
>> the output below it would have been good to log the firmware error as
>> well. And staring at it some more I suddenly realize I broke the
>> feature detection module with this change. Actually only the GSCAN
>> feature detection.
>>
>>> [root@localhost ~]# dmesg | grep brcmfmac
>>> [   34.265950] usbcore: registered new interface driver brcmfmac
>>> [   34.266059] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
>>> [   34.376468] brcmfmac: brcmf_fw_map_chip_to_name: using
>>> brcm/brcmfmac4356-pcie.bin for chip 0x004356(17238) rev 0x000002
>>> [   34.855143] brcmfmac 0000:01:00.0: Direct firmware load for
>>> brcm/brcmfmac4356-pcie.clm_blob failed with error -2
>>> [   34.855147] brcmfmac: brcmf_c_process_clm_blob: no clm_blob
>>> available(err=-2), device may have limited channels available
>>> [   34.857029] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0:
>>> Jun  4 2017 16:50:07 version 7.35.101.6 (r702795) FWID 01-5e8eb735
>>> [   34.938854] brcmfmac 0000:01:00.0 wlp1s0: renamed from wlan0
>>> [   37.086420] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
>>> [   37.086431] brcmfmac: brcmf_cfg80211_add_iface: add iface
>>> p2p-dev-wlp1s0 type 10 failed: err=-52
>>>
>>> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac4356-pcie.bin |
>>> tail -n 1
>>> 4356a2-roml/pcie-ag-msgbuf-splitrx-p2p-pno-aoe-pktfilter-keepalive-sr-mchan-pktctx-proptxstatus-ampduhostreorder-lpc-pwropt-txbf-wl11u-mfp-tdls-amsdutx-sarctrl-proxd-hs20sta-rcc-wepso-ndoe-linkstat-gscan-hchk-logtrace-roamexp-rmon
>>>
>>> Version: 7.35.101.6 (r702795) CRC: 4f3f65c5 Date: Sun 2017-06-04
>>> 16:51:38 PDT Ucode Ver: 963.316 FWID: 01-5e8eb735
>>>
>>> It would be good if we can silence these errors, or maybe at a
>>> minimum lower their log-level from error to warning?
>>
>> I had a look at it and it seems to be a difference in firmware api
>> that we need to support in the driver. Need to do a bit more digging,
>> but it seems an actual issue. You could silence it for now, but I
>> prefer to wait for the fix.
>
> Ok, what is the ETA of a fix for this?

Actually went back to an old log you sent and noticed:

[   15.714569] brcmfmac: brcmf_attach Enter
[   15.714756] brcmfmac: brcmf_fweh_register event handler registered 
for PSM_WATCHDOG
[   15.714757] brcmfmac: brcmf_proto_attach Enter
[   15.716598] brcmfmac: brcmf_bus_started
[   15.716603] brcmfmac: brcmf_add_if Enter, bsscfgidx=0, ifidx=0
[   15.716604] brcmfmac: brcmf_add_if allocate netdev interface
[   15.716622] brcmfmac: brcmf_add_if  ==== pid:2a, if:wlan%d 
(00:00:00:00:00:00) created ===
[   15.716624] brcmfmac: brcmf_bus_change_state 0 -> 1
[   15.717841] brcmfmac: brcmf_fil_iovar_data_get ifidx=0, 
name=cur_etheraddr, len=6
[   15.717843] brcmutil: data
[   15.717847] 00000000: 44 2c 05 9e c9 02 
   D,....

So mac address of the device is 44:2c:05:9e:c9. However, further down I see:

[   17.819113] brcmfmac: brcmf_netdev_set_mac_address Enter, bsscfgidx=0
[   17.819122] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, 
name=cur_etheraddr, len=6
[   17.819127] brcmutil: data
[   17.819135] 00000000: aa 3e 81 77 bc 40 
   .>.w.@
[   17.819864] brcmfmac: brcmf_netdev_set_mac_address updated to 
aa:3e:81:77:bc:40

So the mac address in a local admin variant. Now our firmware has a 
requirement for the p2p-dev interface that it should be different from 
the mac address of the primary interface, ie. wlp1s0 in this log. In 
brcmfmac we try to do that by setting the local admin bit, but... as it 
is already set we end up using the same mac address hence the -EBUSY.

[   17.947704] brcmfmac: brcmf_cfg80211_add_iface enter: p2p-dev-wlp1s0 
type 10
[   17.947714] brcmfmac: brcmf_p2p_add_vif adding vif "p2p-dev-wlp1s0" 
(type=10, addr=00:00:00:00:00:00)
[   17.947716] brcmfmac: brcmf_alloc_vif allocating virtual interface 
(size=3920)
[   17.947720] brcmfmac: brcmf_fil_cmd_int_set ifidx=0, cmd=3, value=1
[   17.948749] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=apsta, len=4
[   17.948752] brcmutil: data
[   17.948756] 00000000: 01 00 00 00 
   ....
[   17.949620] brcmfmac: brcmf_fil_cmd_int_set ifidx=0, cmd=2, value=1
[   17.984420] brcmfmac: brcmf_fweh_event_worker event IF (54) ifidx 0 
bsscfg 0 addr aa:3e:81:77:bc:40
[   17.984424] brcmfmac: brcmf_fweh_event_worker   version 2 flags 0 
status 0 reason 0
[   17.984427] brcmutil: event payload, len=5
[   17.984430] 00000000: 00 01 00 00 00 
   .....
[   17.984433] brcmfmac: brcmf_fweh_handle_if_event action: 1 ifidx: 0 
bsscfgidx: 0 flags: 0 role: 0
[   17.984435] brcmfmac: brcmf_fweh_handle_if_event adding wl0 
(aa:3e:81:77:bc:40)
[   17.984437] brcmfmac: brcmf_add_if Enter, bsscfgidx=0, ifidx=0
[   17.984439] brcmfmac: brcmf_add_if netdev:wlp1s0 ignore IF event
[   17.984646] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, 
name=p2p_disc, len=4
[   17.984657] brcmutil: data
[   17.984669] 00000000: 00 00 00 00 
   ....
[   17.985123] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, 
name=p2p_da_override, len=6
[   17.985131] brcmutil: data
[   17.985140] 00000000: aa 3e 81 77 bc 40 
   .>.w.@
[   17.985580] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, 
name=p2p_disc, len=4
[   17.985588] brcmutil: data
[   17.985598] 00000000: 01 00 00 00 
   ....
[   17.985975] brcmfmac: brcmf_fil_cmd_data Failed: BCME_BUSY (-16)
[   17.985985] brcmfmac: brcmf_p2p_create_p2pdev set p2p_disc error
[   17.985999] brcmfmac: brcmf_cfg80211_add_iface add iface 
p2p-dev-wlp1s0 type 10 failed: err=-16

Sorry that I missed that earlier :-(

Regards,
Arend

> Regards,
>
> Hans
>
>
>
>
>>>> ---
>>>>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14
>>>> ++++++++++----
>>>>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
>>>>   2 files changed, 14 insertions(+), 5 deletions(-)
>>>>
>>>> diff --git
>>>> a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>> index cd1d6730eab7..dae88f3d041d 100644
>>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>> @@ -684,11 +684,17 @@ static struct wireless_dev
>>>> *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
>>>>           return ERR_PTR(-EINVAL);
>>>>       }
>>>> -    if (IS_ERR(wdev))
>>>> -        brcmf_err("add iface %s type %d failed: err=%d\n",
>>>> -              name, type, (int)PTR_ERR(wdev));
>>>> -    else
>>>> +    if (IS_ERR(wdev)) {
>>>> +        err = PTR_ERR(wdev);
>>>> +        if (err != -EBUSY)
>>>> +            brcmf_err("add iface %s type %d failed: err=%d\n",
>>>> +                  name, type, err);
>>>> +        else
>>>> +            brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
>>>> +                  name, type, err);
>>>> +    } else {
>>>>           brcmf_cfg80211_update_proto_addr_mode(wdev);
>>>> +    }
>>>>       return wdev;
>>>>   }
>>>> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>> index aa299c47bfa2..1bb296ffb46f 100644
>>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>> @@ -2090,7 +2090,10 @@ static struct wireless_dev
>>>> *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
>>>>       /* Initialize P2P Discovery in the firmware */
>>>>       err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
>>>>       if (err < 0) {
>>>> -        brcmf_err("set p2p_disc error\n");
>>>> +        if (err != -EBUSY)
>>>> +            brcmf_err("set p2p_disc error\n");
>>>> +        else
>>>> +            brcmf_dbg(INFO, "set p2p_disc error\n");
>>>>           brcmf_fweh_p2pdev_setup(pri_ifp, false);
>>>>           brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
>>>>           goto fail;
>>>>
>>
Hans de Goede Feb. 26, 2018, 11:22 a.m. UTC | #10
Hi,

On 26-02-18 12:01, Arend van Spriel wrote:
> On 2/26/2018 11:29 AM, Hans de Goede wrote:
>> Hi,
>>
>> On 26-02-18 11:22, Arend van Spriel wrote:
>>> On 2/25/2018 3:52 PM, Hans de Goede wrote:
>>>> Hi,
>>>>
>>>> On 26-05-17 12:57, Hans de Goede wrote:
>>>>> The firmware responding with -EBUSY when trying to add an extra
>>>>> virtual-if
>>>>> is a normal thing, do not print an error for this.
>>>>>
>>>>> Signed-off-by: Hans de Goede <hdegoede@redhat.com>
>>>>
>>>> I'm now seeing this on another device too, but this time the error
>>>> thrown is -EBADE, this seems to be new with recent kernels:
>>>
>>> Yup. Before we were passing firmware errors up to user-space, which
>>> was confusing and potentially be misinterpreted. However, looking at
>>> the output below it would have been good to log the firmware error as
>>> well. And staring at it some more I suddenly realize I broke the
>>> feature detection module with this change. Actually only the GSCAN
>>> feature detection.
>>>
>>>> [root@localhost ~]# dmesg | grep brcmfmac
>>>> [   34.265950] usbcore: registered new interface driver brcmfmac
>>>> [   34.266059] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
>>>> [   34.376468] brcmfmac: brcmf_fw_map_chip_to_name: using
>>>> brcm/brcmfmac4356-pcie.bin for chip 0x004356(17238) rev 0x000002
>>>> [   34.855143] brcmfmac 0000:01:00.0: Direct firmware load for
>>>> brcm/brcmfmac4356-pcie.clm_blob failed with error -2
>>>> [   34.855147] brcmfmac: brcmf_c_process_clm_blob: no clm_blob
>>>> available(err=-2), device may have limited channels available
>>>> [   34.857029] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0:
>>>> Jun  4 2017 16:50:07 version 7.35.101.6 (r702795) FWID 01-5e8eb735
>>>> [   34.938854] brcmfmac 0000:01:00.0 wlp1s0: renamed from wlan0
>>>> [   37.086420] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
>>>> [   37.086431] brcmfmac: brcmf_cfg80211_add_iface: add iface
>>>> p2p-dev-wlp1s0 type 10 failed: err=-52
>>>>
>>>> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac4356-pcie.bin |
>>>> tail -n 1
>>>> 4356a2-roml/pcie-ag-msgbuf-splitrx-p2p-pno-aoe-pktfilter-keepalive-sr-mchan-pktctx-proptxstatus-ampduhostreorder-lpc-pwropt-txbf-wl11u-mfp-tdls-amsdutx-sarctrl-proxd-hs20sta-rcc-wepso-ndoe-linkstat-gscan-hchk-logtrace-roamexp-rmon
>>>>
>>>> Version: 7.35.101.6 (r702795) CRC: 4f3f65c5 Date: Sun 2017-06-04
>>>> 16:51:38 PDT Ucode Ver: 963.316 FWID: 01-5e8eb735
>>>>
>>>> It would be good if we can silence these errors, or maybe at a
>>>> minimum lower their log-level from error to warning?
>>>
>>> I had a look at it and it seems to be a difference in firmware api
>>> that we need to support in the driver. Need to do a bit more digging,
>>> but it seems an actual issue. You could silence it for now, but I
>>> prefer to wait for the fix.
>>
>> Ok, what is the ETA of a fix for this?
> 
> Actually went back to an old log you sent and noticed:
> 
> [   15.714569] brcmfmac: brcmf_attach Enter
> [   15.714756] brcmfmac: brcmf_fweh_register event handler registered for PSM_WATCHDOG
> [   15.714757] brcmfmac: brcmf_proto_attach Enter
> [   15.716598] brcmfmac: brcmf_bus_started
> [   15.716603] brcmfmac: brcmf_add_if Enter, bsscfgidx=0, ifidx=0
> [   15.716604] brcmfmac: brcmf_add_if allocate netdev interface
> [   15.716622] brcmfmac: brcmf_add_if  ==== pid:2a, if:wlan%d (00:00:00:00:00:00) created ===
> [   15.716624] brcmfmac: brcmf_bus_change_state 0 -> 1
> [   15.717841] brcmfmac: brcmf_fil_iovar_data_get ifidx=0, name=cur_etheraddr, len=6
> [   15.717843] brcmutil: data
> [   15.717847] 00000000: 44 2c 05 9e c9 02   D,....
> 
> So mac address of the device is 44:2c:05:9e:c9. However, further down I see:
> 
> [   17.819113] brcmfmac: brcmf_netdev_set_mac_address Enter, bsscfgidx=0
> [   17.819122] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=cur_etheraddr, len=6
> [   17.819127] brcmutil: data
> [   17.819135] 00000000: aa 3e 81 77 bc 40   .>.w.@
> [   17.819864] brcmfmac: brcmf_netdev_set_mac_address updated to aa:3e:81:77:bc:40
> 
> So the mac address in a local admin variant.

Right, this is likely NetworkManager randomizing the mac for privacy reasons.

> Now our firmware has a requirement for the p2p-dev interface that it should be different from the mac address of the primary interface, ie. wlp1s0 in this log. In brcmfmac we try to do that by setting the local admin bit, but... as it is already set we end up using the same mac address hence the -EBUSY.

Ah, that is good to know, so how can we fix this? Can userspace specify a
different mac-address when it asks for the p2p-dev intf to be created? Or
should we do something about this in the kernel?

Regards,

Hans


> [   17.947704] brcmfmac: brcmf_cfg80211_add_iface enter: p2p-dev-wlp1s0 type 10
> [   17.947714] brcmfmac: brcmf_p2p_add_vif adding vif "p2p-dev-wlp1s0" (type=10, addr=00:00:00:00:00:00)
> [   17.947716] brcmfmac: brcmf_alloc_vif allocating virtual interface (size=3920)
> [   17.947720] brcmfmac: brcmf_fil_cmd_int_set ifidx=0, cmd=3, value=1
> [   17.948749] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=apsta, len=4
> [   17.948752] brcmutil: data
> [   17.948756] 00000000: 01 00 00 00   ....
> [   17.949620] brcmfmac: brcmf_fil_cmd_int_set ifidx=0, cmd=2, value=1
> [   17.984420] brcmfmac: brcmf_fweh_event_worker event IF (54) ifidx 0 bsscfg 0 addr aa:3e:81:77:bc:40
> [   17.984424] brcmfmac: brcmf_fweh_event_worker   version 2 flags 0 status 0 reason 0
> [   17.984427] brcmutil: event payload, len=5
> [   17.984430] 00000000: 00 01 00 00 00   .....
> [   17.984433] brcmfmac: brcmf_fweh_handle_if_event action: 1 ifidx: 0 bsscfgidx: 0 flags: 0 role: 0
> [   17.984435] brcmfmac: brcmf_fweh_handle_if_event adding wl0 (aa:3e:81:77:bc:40)
> [   17.984437] brcmfmac: brcmf_add_if Enter, bsscfgidx=0, ifidx=0
> [   17.984439] brcmfmac: brcmf_add_if netdev:wlp1s0 ignore IF event
> [   17.984646] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=p2p_disc, len=4
> [   17.984657] brcmutil: data
> [   17.984669] 00000000: 00 00 00 00   ....
> [   17.985123] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=p2p_da_override, len=6
> [   17.985131] brcmutil: data
> [   17.985140] 00000000: aa 3e 81 77 bc 40   .>.w.@
> [   17.985580] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=p2p_disc, len=4
> [   17.985588] brcmutil: data
> [   17.985598] 00000000: 01 00 00 00   ....
> [   17.985975] brcmfmac: brcmf_fil_cmd_data Failed: BCME_BUSY (-16)
> [   17.985985] brcmfmac: brcmf_p2p_create_p2pdev set p2p_disc error
> [   17.985999] brcmfmac: brcmf_cfg80211_add_iface add iface p2p-dev-wlp1s0 type 10 failed: err=-16
> 
> Sorry that I missed that earlier :-(
> 
> Regards,
> Arend
> 
>> Regards,
>>
>> Hans
>>
>>
>>
>>
>>>>> ---
>>>>>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14
>>>>> ++++++++++----
>>>>>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5 ++++-
>>>>>   2 files changed, 14 insertions(+), 5 deletions(-)
>>>>>
>>>>> diff --git
>>>>> a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>> index cd1d6730eab7..dae88f3d041d 100644
>>>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>> @@ -684,11 +684,17 @@ static struct wireless_dev
>>>>> *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
>>>>>           return ERR_PTR(-EINVAL);
>>>>>       }
>>>>> -    if (IS_ERR(wdev))
>>>>> -        brcmf_err("add iface %s type %d failed: err=%d\n",
>>>>> -              name, type, (int)PTR_ERR(wdev));
>>>>> -    else
>>>>> +    if (IS_ERR(wdev)) {
>>>>> +        err = PTR_ERR(wdev);
>>>>> +        if (err != -EBUSY)
>>>>> +            brcmf_err("add iface %s type %d failed: err=%d\n",
>>>>> +                  name, type, err);
>>>>> +        else
>>>>> +            brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
>>>>> +                  name, type, err);
>>>>> +    } else {
>>>>>           brcmf_cfg80211_update_proto_addr_mode(wdev);
>>>>> +    }
>>>>>       return wdev;
>>>>>   }
>>>>> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>> index aa299c47bfa2..1bb296ffb46f 100644
>>>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>> @@ -2090,7 +2090,10 @@ static struct wireless_dev
>>>>> *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
>>>>>       /* Initialize P2P Discovery in the firmware */
>>>>>       err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
>>>>>       if (err < 0) {
>>>>> -        brcmf_err("set p2p_disc error\n");
>>>>> +        if (err != -EBUSY)
>>>>> +            brcmf_err("set p2p_disc error\n");
>>>>> +        else
>>>>> +            brcmf_dbg(INFO, "set p2p_disc error\n");
>>>>>           brcmf_fweh_p2pdev_setup(pri_ifp, false);
>>>>>           brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
>>>>>           goto fail;
>>>>>
>>>
>
Arend Van Spriel Feb. 26, 2018, 11:36 a.m. UTC | #11
On 2/26/2018 12:22 PM, Hans de Goede wrote:
> Hi,
>
> On 26-02-18 12:01, Arend van Spriel wrote:
>> On 2/26/2018 11:29 AM, Hans de Goede wrote:
>>> Hi,
>>>
>>> On 26-02-18 11:22, Arend van Spriel wrote:
>>>> On 2/25/2018 3:52 PM, Hans de Goede wrote:
>>>>> Hi,
>>>>>
>>>>> On 26-05-17 12:57, Hans de Goede wrote:
>>>>>> The firmware responding with -EBUSY when trying to add an extra
>>>>>> virtual-if
>>>>>> is a normal thing, do not print an error for this.
>>>>>>
>>>>>> Signed-off-by: Hans de Goede <hdegoede@redhat.com>
>>>>>
>>>>> I'm now seeing this on another device too, but this time the error
>>>>> thrown is -EBADE, this seems to be new with recent kernels:
>>>>
>>>> Yup. Before we were passing firmware errors up to user-space, which
>>>> was confusing and potentially be misinterpreted. However, looking at
>>>> the output below it would have been good to log the firmware error as
>>>> well. And staring at it some more I suddenly realize I broke the
>>>> feature detection module with this change. Actually only the GSCAN
>>>> feature detection.
>>>>
>>>>> [root@localhost ~]# dmesg | grep brcmfmac
>>>>> [   34.265950] usbcore: registered new interface driver brcmfmac
>>>>> [   34.266059] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
>>>>> [   34.376468] brcmfmac: brcmf_fw_map_chip_to_name: using
>>>>> brcm/brcmfmac4356-pcie.bin for chip 0x004356(17238) rev 0x000002
>>>>> [   34.855143] brcmfmac 0000:01:00.0: Direct firmware load for
>>>>> brcm/brcmfmac4356-pcie.clm_blob failed with error -2
>>>>> [   34.855147] brcmfmac: brcmf_c_process_clm_blob: no clm_blob
>>>>> available(err=-2), device may have limited channels available
>>>>> [   34.857029] brcmfmac: brcmf_c_preinit_dcmds: Firmware version =
>>>>> wl0:
>>>>> Jun  4 2017 16:50:07 version 7.35.101.6 (r702795) FWID 01-5e8eb735
>>>>> [   34.938854] brcmfmac 0000:01:00.0 wlp1s0: renamed from wlan0
>>>>> [   37.086420] brcmfmac: brcmf_p2p_create_p2pdev: set p2p_disc error
>>>>> [   37.086431] brcmfmac: brcmf_cfg80211_add_iface: add iface
>>>>> p2p-dev-wlp1s0 type 10 failed: err=-52
>>>>>
>>>>> [root@localhost ~]# strings /lib/firmware/brcm/brcmfmac4356-pcie.bin |
>>>>> tail -n 1
>>>>> 4356a2-roml/pcie-ag-msgbuf-splitrx-p2p-pno-aoe-pktfilter-keepalive-sr-mchan-pktctx-proptxstatus-ampduhostreorder-lpc-pwropt-txbf-wl11u-mfp-tdls-amsdutx-sarctrl-proxd-hs20sta-rcc-wepso-ndoe-linkstat-gscan-hchk-logtrace-roamexp-rmon
>>>>>
>>>>>
>>>>> Version: 7.35.101.6 (r702795) CRC: 4f3f65c5 Date: Sun 2017-06-04
>>>>> 16:51:38 PDT Ucode Ver: 963.316 FWID: 01-5e8eb735
>>>>>
>>>>> It would be good if we can silence these errors, or maybe at a
>>>>> minimum lower their log-level from error to warning?
>>>>
>>>> I had a look at it and it seems to be a difference in firmware api
>>>> that we need to support in the driver. Need to do a bit more digging,
>>>> but it seems an actual issue. You could silence it for now, but I
>>>> prefer to wait for the fix.
>>>
>>> Ok, what is the ETA of a fix for this?
>>
>> Actually went back to an old log you sent and noticed:
>>
>> [   15.714569] brcmfmac: brcmf_attach Enter
>> [   15.714756] brcmfmac: brcmf_fweh_register event handler registered
>> for PSM_WATCHDOG
>> [   15.714757] brcmfmac: brcmf_proto_attach Enter
>> [   15.716598] brcmfmac: brcmf_bus_started
>> [   15.716603] brcmfmac: brcmf_add_if Enter, bsscfgidx=0, ifidx=0
>> [   15.716604] brcmfmac: brcmf_add_if allocate netdev interface
>> [   15.716622] brcmfmac: brcmf_add_if  ==== pid:2a, if:wlan%d
>> (00:00:00:00:00:00) created ===
>> [   15.716624] brcmfmac: brcmf_bus_change_state 0 -> 1
>> [   15.717841] brcmfmac: brcmf_fil_iovar_data_get ifidx=0,
>> name=cur_etheraddr, len=6
>> [   15.717843] brcmutil: data
>> [   15.717847] 00000000: 44 2c 05 9e c9 02   D,....
>>
>> So mac address of the device is 44:2c:05:9e:c9. However, further down
>> I see:
>>
>> [   17.819113] brcmfmac: brcmf_netdev_set_mac_address Enter, bsscfgidx=0
>> [   17.819122] brcmfmac: brcmf_fil_iovar_data_set ifidx=0,
>> name=cur_etheraddr, len=6
>> [   17.819127] brcmutil: data
>> [   17.819135] 00000000: aa 3e 81 77 bc 40   .>.w.@
>> [   17.819864] brcmfmac: brcmf_netdev_set_mac_address updated to
>> aa:3e:81:77:bc:40
>>
>> So the mac address in a local admin variant.
>
> Right, this is likely NetworkManager randomizing the mac for privacy
> reasons.
>
>> Now our firmware has a requirement for the p2p-dev interface that it
>> should be different from the mac address of the primary interface, ie.
>> wlp1s0 in this log. In brcmfmac we try to do that by setting the local
>> admin bit, but... as it is already set we end up using the same mac
>> address hence the -EBUSY.
>
> Ah, that is good to know, so how can we fix this? Can userspace specify a
> different mac-address when it asks for the p2p-dev intf to be created? Or
> should we do something about this in the kernel?

The nl80211 api allows user-space to provide a mac address for the newly 
created interface since kernel 3.something. So for legacy user-space we 
use the behavior above as fallback. I am testing a patch right now.

Regards,
Arend

> Regards,
>
> Hans
>
>
>> [   17.947704] brcmfmac: brcmf_cfg80211_add_iface enter:
>> p2p-dev-wlp1s0 type 10
>> [   17.947714] brcmfmac: brcmf_p2p_add_vif adding vif "p2p-dev-wlp1s0"
>> (type=10, addr=00:00:00:00:00:00)
>> [   17.947716] brcmfmac: brcmf_alloc_vif allocating virtual interface
>> (size=3920)
>> [   17.947720] brcmfmac: brcmf_fil_cmd_int_set ifidx=0, cmd=3, value=1
>> [   17.948749] brcmfmac: brcmf_fil_iovar_data_set ifidx=0, name=apsta,
>> len=4
>> [   17.948752] brcmutil: data
>> [   17.948756] 00000000: 01 00 00 00   ....
>> [   17.949620] brcmfmac: brcmf_fil_cmd_int_set ifidx=0, cmd=2, value=1
>> [   17.984420] brcmfmac: brcmf_fweh_event_worker event IF (54) ifidx 0
>> bsscfg 0 addr aa:3e:81:77:bc:40
>> [   17.984424] brcmfmac: brcmf_fweh_event_worker   version 2 flags 0
>> status 0 reason 0
>> [   17.984427] brcmutil: event payload, len=5
>> [   17.984430] 00000000: 00 01 00 00 00   .....
>> [   17.984433] brcmfmac: brcmf_fweh_handle_if_event action: 1 ifidx: 0
>> bsscfgidx: 0 flags: 0 role: 0
>> [   17.984435] brcmfmac: brcmf_fweh_handle_if_event adding wl0
>> (aa:3e:81:77:bc:40)
>> [   17.984437] brcmfmac: brcmf_add_if Enter, bsscfgidx=0, ifidx=0
>> [   17.984439] brcmfmac: brcmf_add_if netdev:wlp1s0 ignore IF event
>> [   17.984646] brcmfmac: brcmf_fil_iovar_data_set ifidx=0,
>> name=p2p_disc, len=4
>> [   17.984657] brcmutil: data
>> [   17.984669] 00000000: 00 00 00 00   ....
>> [   17.985123] brcmfmac: brcmf_fil_iovar_data_set ifidx=0,
>> name=p2p_da_override, len=6
>> [   17.985131] brcmutil: data
>> [   17.985140] 00000000: aa 3e 81 77 bc 40   .>.w.@
>> [   17.985580] brcmfmac: brcmf_fil_iovar_data_set ifidx=0,
>> name=p2p_disc, len=4
>> [   17.985588] brcmutil: data
>> [   17.985598] 00000000: 01 00 00 00   ....
>> [   17.985975] brcmfmac: brcmf_fil_cmd_data Failed: BCME_BUSY (-16)
>> [   17.985985] brcmfmac: brcmf_p2p_create_p2pdev set p2p_disc error
>> [   17.985999] brcmfmac: brcmf_cfg80211_add_iface add iface
>> p2p-dev-wlp1s0 type 10 failed: err=-16
>>
>> Sorry that I missed that earlier :-(
>>
>> Regards,
>> Arend
>>
>>> Regards,
>>>
>>> Hans
>>>
>>>
>>>
>>>
>>>>>> ---
>>>>>>   .../net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c    | 14
>>>>>> ++++++++++----
>>>>>>   drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c     |  5
>>>>>> ++++-
>>>>>>   2 files changed, 14 insertions(+), 5 deletions(-)
>>>>>>
>>>>>> diff --git
>>>>>> a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>>> index cd1d6730eab7..dae88f3d041d 100644
>>>>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
>>>>>> @@ -684,11 +684,17 @@ static struct wireless_dev
>>>>>> *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
>>>>>>           return ERR_PTR(-EINVAL);
>>>>>>       }
>>>>>> -    if (IS_ERR(wdev))
>>>>>> -        brcmf_err("add iface %s type %d failed: err=%d\n",
>>>>>> -              name, type, (int)PTR_ERR(wdev));
>>>>>> -    else
>>>>>> +    if (IS_ERR(wdev)) {
>>>>>> +        err = PTR_ERR(wdev);
>>>>>> +        if (err != -EBUSY)
>>>>>> +            brcmf_err("add iface %s type %d failed: err=%d\n",
>>>>>> +                  name, type, err);
>>>>>> +        else
>>>>>> +            brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
>>>>>> +                  name, type, err);
>>>>>> +    } else {
>>>>>>           brcmf_cfg80211_update_proto_addr_mode(wdev);
>>>>>> +    }
>>>>>>       return wdev;
>>>>>>   }
>>>>>> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>>> index aa299c47bfa2..1bb296ffb46f 100644
>>>>>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
>>>>>> @@ -2090,7 +2090,10 @@ static struct wireless_dev
>>>>>> *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
>>>>>>       /* Initialize P2P Discovery in the firmware */
>>>>>>       err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
>>>>>>       if (err < 0) {
>>>>>> -        brcmf_err("set p2p_disc error\n");
>>>>>> +        if (err != -EBUSY)
>>>>>> +            brcmf_err("set p2p_disc error\n");
>>>>>> +        else
>>>>>> +            brcmf_dbg(INFO, "set p2p_disc error\n");
>>>>>>           brcmf_fweh_p2pdev_setup(pri_ifp, false);
>>>>>>           brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
>>>>>>           goto fail;
>>>>>>
>>>>
>>
diff mbox

Patch

diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
index cd1d6730eab7..dae88f3d041d 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c
@@ -684,11 +684,17 @@  static struct wireless_dev *brcmf_cfg80211_add_iface(struct wiphy *wiphy,
 		return ERR_PTR(-EINVAL);
 	}
 
-	if (IS_ERR(wdev))
-		brcmf_err("add iface %s type %d failed: err=%d\n",
-			  name, type, (int)PTR_ERR(wdev));
-	else
+	if (IS_ERR(wdev)) {
+		err = PTR_ERR(wdev);
+		if (err != -EBUSY)
+			brcmf_err("add iface %s type %d failed: err=%d\n",
+				  name, type, err);
+		else
+			brcmf_dbg(INFO, "add iface %s type %d failed: err=%d\n",
+				  name, type, err);
+	} else {
 		brcmf_cfg80211_update_proto_addr_mode(wdev);
+	}
 
 	return wdev;
 }
diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
index aa299c47bfa2..1bb296ffb46f 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/p2p.c
@@ -2090,7 +2090,10 @@  static struct wireless_dev *brcmf_p2p_create_p2pdev(struct brcmf_p2p_info *p2p,
 	/* Initialize P2P Discovery in the firmware */
 	err = brcmf_fil_iovar_int_set(pri_ifp, "p2p_disc", 1);
 	if (err < 0) {
-		brcmf_err("set p2p_disc error\n");
+		if (err != -EBUSY)
+			brcmf_err("set p2p_disc error\n");
+		else
+			brcmf_dbg(INFO, "set p2p_disc error\n");
 		brcmf_fweh_p2pdev_setup(pri_ifp, false);
 		brcmf_cfg80211_arm_vif_event(p2p->cfg, NULL);
 		goto fail;