Re: brcmfmac: Unexpected brcmf_set_channel: set chanspec 0xd022 fail, reason -52 - Part 2

[Arend Van Spriel <arend.vanspriel@xxxxxxxxxxxx>]

On January 16, 2024 3:09:45 PM Johannes Berg <johannes@xxxxxxxxxxxxxxxx> wrote:

> On Tue, 2023-12-26 at 20:27 +0100, Stefan Wahren wrote:
> > Hi Arend,
> >
> > [add Johannes]
>
> Sorry this fell through, Intel address ...
>
> Was there a specific question you had?
>
> > > > > [  334.956787] cfg80211: Calling CRDA for country: DE
> > > >
> > > > I guess this message is a bit stale and there is no crda user-mode
> > > > helper.
>
> It may still try to call it, but I guess nothing will happen.
>
> > > > > [  334.990709] cfg80211: Disabling freq 2484.000 MHz
> > > >
> > > > So 2GHz channel 14 gets disabled here probably due to country change
> > > > to DE.
> > > >
> > > > Not learned a whole lot more from this test round except that reg.c is
> > > > active during the reconnect so I suggest to zoom in there. Especially
> > > > around the "restoring" message.
> > >
> > > I wonder whether we end up in restore_custom_reg_settings() which does:
> > >
> > > chan->flags = chan->orig_flags;
> > >
> > > for each channel. That would re-enable those channels.
> > Bingo
> >
> > This caused the problem. Since brcmf_construct_chaninfo() is only called
> > once and only changes the flags but never orig_flags, the information
> > about disabled channels get lost (logs are focused on hw_value 34):
> >
> > [   10.294909] cfg80211: Loading compiled-in X.509 certificates for
> > regulatory database
> > [   10.717262] brcmfmac: brcmf_fw_alloc_request: using
> > brcm/brcmfmac43455-sdio for chip BCM4345/6
> > [   10.718408] cfg80211: loaded regulatory.db is malformed or signature
> > is missing/invalid
> > [   10.718427] cfg80211: Restoring regulatory settings
> > [   10.718435] cfg80211: Kicking the queue
> > [   10.718452] cfg80211: Calling CRDA to update world regulatory domain
> > [   10.948418] brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob
> > available (err=-2)
> > [   10.948764] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0:
> > Nov  1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
> > [   10.982088] cfg80211: handle_channel_custom: hw_value 34, orig_flags:
> > 00000000, flags 00000000
> > [   10.982346] cfg80211: Ignoring regulatory request set by core since
> > the driver uses its own custom regulatory domain
> >
> > The channel 34 has been disabled by brcmf_construct_chaninfo():
> > [   11.025681] brcmfmac: brcmf_construct_chaninfo: hw_value 34,
> > orig_flags: 00080000, flags 00000001
> > [   13.045508] cfg80211: Pending regulatory request, waiting for it to
> > be processed...
> > [   13.237669] cfg80211: Ignoring regulatory request set by core since
> > the driver uses its own custom regulatory domain
> > [   13.237692] cfg80211: World regulatory domain updated:
> > [   13.237696] cfg80211:  DFS Master region: unset
> > [   13.237701] cfg80211:   (start_freq - end_freq @ bandwidth),
> > (max_antenna_gain, max_eirp), (dfs_cac_time)
> > [   13.237709] cfg80211:   (755000 KHz - 928000 KHz @ 2000 KHz), (N/A,
> > 2000 mBm), (N/A)
> > [   13.237717] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz),
> > (N/A, 2000 mBm), (N/A)
> > [   13.237726] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000
> > KHz AUTO), (N/A, 2000 mBm), (N/A)
> > [   13.237734] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz),
> > (N/A, 2000 mBm), (N/A)
> > [   13.237742] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz,
> > 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
> > [   13.237750] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz,
> > 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
> > [   13.237758] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz),
> > (N/A, 2000 mBm), (0 s)
> > [   13.237765] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz),
> > (N/A, 2000 mBm), (N/A)
> > [   13.237772] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz),
> > (N/A, 0 mBm), (N/A)
> > [   13.237814] cfg80211: Calling CRDA for country: DE
> > [   13.262648] cfg80211: Disabling freq 2484.000 MHz
> > [   13.262687] cfg80211: handle_channel: hw_value 34, orig_flags:
> > 00080000, flags 00000001
> > [   13.262696] cfg80211: handle_channel_single_rule: hw_value 34,
> > orig_flags: 00080000, flags 00000001
> > [   13.359105] brcmfmac: brcmf_construct_chaninfo: hw_value 34,
> > orig_flags: 00080000, flags 00000001
> > [   13.360210] cfg80211: Regulatory domain changed to country: DE
> > [   13.360231] cfg80211:  DFS Master region: ETSI
> > [   13.360235] cfg80211:   (start_freq - end_freq @ bandwidth),
> > (max_antenna_gain, max_eirp), (dfs_cac_time)
> > [   13.360246] cfg80211:   (2400000 KHz - 2483500 KHz @ 40000 KHz),
> > (N/A, 2000 mBm), (N/A)
> > [   13.360256] cfg80211:   (5150000 KHz - 5250000 KHz @ 80000 KHz,
> > 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
> > [   13.360265] cfg80211:   (5250000 KHz - 5350000 KHz @ 80000 KHz,
> > 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
> > [   13.360281] cfg80211:   (5470000 KHz - 5725000 KHz @ 160000 KHz),
> > (N/A, 2698 mBm), (0 s)
> > [   13.360289] cfg80211:   (5725000 KHz - 5875000 KHz @ 80000 KHz),
> > (N/A, 1397 mBm), (N/A)
> > [   13.360296] cfg80211:   (5945000 KHz - 6425000 KHz @ 160000 KHz,
> > 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
> > [   13.360303] cfg80211:   (57000000 KHz - 66000000 KHz @ 2160000 KHz),
> > (N/A, 4000 mBm), (N/A)
> > [   17.172301] cfg80211: Found new beacon on frequency: 5180.000 MHz (Ch
> > 36) on phy0
> > [   17.172326] cfg80211: Found new beacon on frequency: 5220.000 MHz (Ch
> > 44) on phy0
> > [   20.800666] cfg80211: Calling CRDA for country: DE
> > [   20.834453] cfg80211: Disabling freq 2484.000 MHz
> > [   20.834487] cfg80211: handle_channel: hw_value 34, orig_flags:
> > 00080000, flags 00000001
> > [   20.834503] cfg80211: handle_channel_single_rule: hw_value 34,
> > orig_flags: 00080000, flags 00000001
> > [   20.835045] cfg80211: Regulatory domain changed to country: DE
> > [   20.835057] cfg80211:  DFS Master region: ETSI
> > [   20.835063] cfg80211:   (start_freq - end_freq @ bandwidth),
> > (max_antenna_gain, max_eirp), (dfs_cac_time)
> > [   20.835075] cfg80211:   (2400000 KHz - 2483500 KHz @ 40000 KHz),
> > (N/A, 2000 mBm), (N/A)
> > [   20.835095] cfg80211:   (5150000 KHz - 5250000 KHz @ 80000 KHz,
> > 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
> > [   20.835109] cfg80211:   (5250000 KHz - 5350000 KHz @ 80000 KHz,
> > 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
> > [   20.835122] cfg80211:   (5470000 KHz - 5725000 KHz @ 160000 KHz),
> > (N/A, 2698 mBm), (0 s)
> > [   20.835135] cfg80211:   (5725000 KHz - 5875000 KHz @ 80000 KHz),
> > (N/A, 1397 mBm), (N/A)
> > [   20.835148] cfg80211:   (5945000 KHz - 6425000 KHz @ 160000 KHz,
> > 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
> > [   20.835160] cfg80211:   (57000000 KHz - 66000000 KHz @ 2160000 KHz),
> > (N/A, 4000 mBm), (N/A)
> > [   84.952323] cfg80211: Verifying active interfaces after reg change
> > [  344.070588] cfg80211: All devices are disconnected, going to restore
> > regulatory settings
> > [  344.070619] cfg80211: Restoring regulatory settings while preserving
> > user preference for: DE
> >
> > Dump after restore_custom_reg_settings() is finished (channel 34 is
> > re-enabled):
> > [  344.070639] cfg80211: restore_custom_reg_settings: hw_value 34,
> > orig_flags: 00080000, flags 00080000
> > [  344.070660] cfg80211: Ignoring regulatory request set by core since
> > the driver uses its own custom regulatory domain
> > [  344.070675] cfg80211: World regulatory domain updated:
> > [  344.070684] cfg80211:  DFS Master region: unset
> > [  344.070692] cfg80211:   (start_freq - end_freq @ bandwidth),
> > (max_antenna_gain, max_eirp), (dfs_cac_time)
> > [  344.070706] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (600
> > mBi, 2000 mBm), (N/A)
> > [  344.070724] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000
> > KHz AUTO), (600 mBi, 2000 mBm), (N/A)
> > [  344.070741] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (600
> > mBi, 2000 mBm), (N/A)
> > [  344.070758] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz,
> > 160000 KHz AUTO), (600 mBi, 2000 mBm), (N/A)
> > [  344.070775] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz,
> > 160000 KHz AUTO), (600 mBi, 2000 mBm), (0 s)
> > [  344.070792] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz),
> > (600 mBi, 2000 mBm), (0 s)
> > [  344.070808] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (600
> > mBi, 2000 mBm), (N/A)
> > [  344.070824] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz),
> > (N/A, 0 mBm), (N/A)
> > [  344.070881] cfg80211: Disabling freq 2484.000 MHz
> > [  344.070893] cfg80211: handle_channel: hw_value 34, orig_flags:
> > 00080000, flags 00080000
> > [  344.070916] cfg80211: handle_channel_single_rule: hw_value 34,
> > orig_flags: 00080000, flags 00080000
> > [  344.071487] cfg80211: Regulatory domain changed to country: DE
> > [  344.071499] cfg80211:  DFS Master region: ETSI
> > [  344.071506] cfg80211:   (start_freq - end_freq @ bandwidth),
> > (max_antenna_gain, max_eirp), (dfs_cac_time)
> > [  344.071519] cfg80211:   (2400000 KHz - 2483500 KHz @ 40000 KHz),
> > (N/A, 2000 mBm), (N/A)
> > [  344.071536] cfg80211:   (5150000 KHz - 5250000 KHz @ 80000 KHz,
> > 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
> > [  344.071552] cfg80211:   (5250000 KHz - 5350000 KHz @ 80000 KHz,
> > 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
> > [  344.071567] cfg80211:   (5470000 KHz - 5725000 KHz @ 160000 KHz),
> > (N/A, 2698 mBm), (0 s)
> > [  344.071582] cfg80211:   (5725000 KHz - 5875000 KHz @ 80000 KHz),
> > (N/A, 1397 mBm), (N/A)
> > [  344.071597] cfg80211:   (5945000 KHz - 6425000 KHz @ 160000 KHz,
> > 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
> > [  344.071611] cfg80211:   (57000000 KHz - 66000000 KHz @ 2160000 KHz),
> > (N/A, 4000 mBm), (N/A)
> > [  344.071634] cfg80211: Kicking the queue
> > [  344.745318] cfg80211: Found new beacon on frequency: 5180.000 MHz (Ch
> > 36) on phy0
> > [  344.745369] cfg80211: Found new beacon on frequency: 5220.000 MHz (Ch
> > 44) on phy0
> > [  346.174985] brcmfmac: set chanspec 0xd022 fail, reason -52
> > [  346.175018] brcmfmac: hw_value 34, orig_flags: 00080000, flags 00080220
> > > Have you always seen this or at certain kernel update or
> > > wpa_supplicant maybe?
> > As written in the initial message i've tested Linux 6.3, 6.6 and 6.7-rc6
> > with wpa_supplicant 2.9 so far and saw this issue in these cases.
> >
> > How far should i go?
> >
> > I modified brcmf_construct_chaninfo() to store the
> > IEEE80211_CHAN_DISABLED flag within orig_flags in case the flags had it.
> > This avoid the issue. Not sure this is the proper solution.
>
> orig_flags are from when the wiphy is registered - does the driver only
> set up proper flags after that?

Long time ago we discussed about this. So brcmfmac provides a superset of 
channels during wiphy_register() and none of them are disabled as they 
could never be enabled. After that the driver may disable a subset as it 
syncs with the device. I think we used strict custom reg flag, but that 
seems to have gone. Could that have the result Stefan is observing?

Regards,
Arend

> johannes

Attachment: smime.p7s
Description: S/MIME Cryptographic Signature