On December 22, 2023 4:18:19 PM Arend Van Spriel
<[email protected]> wrote:
> On December 21, 2023 7:40:46 PM Stefan Wahren <[email protected]> wrote:
>
>> Hi Arend,
>>
>> Am 21.12.23 um 18:47 schrieb Arend Van Spriel:
>>>
>>>
>>> On November 18, 2023 12:43:24 PM Stefan Wahren <[email protected]> wrote:
>>>
>>>> Hi Arend,
>>>>
>>>> Am 15.11.23 um 21:09 schrieb Arend van Spriel:
>>>>> On 11/15/2023 7:35 PM, Stefan Wahren wrote:
>>>>>> Am 15.11.23 um 10:34 schrieb Arend van Spriel:
>>>>>>> On 11/13/2023 10:02 PM, Stefan Wahren wrote:
>>>>>>>> Hi Arend,
>>>>>>>>
>>>>>>>> Am 13.11.23 um 10:11 schrieb Arend van Spriel:
>>>>>>>>> On 11/11/2023 9:30 PM, Stefan Wahren wrote:
>>>>>>>>>> Am 11.11.23 um 19:29 schrieb Stefan Wahren:
>>>>>>>>>>>
>>>>>>>>>>> Am 11.11.23 um 18:25 schrieb Arend Van Spriel:
>>>>>>>>>>>> On November 11, 2023 5:48:46 PM Stefan Wahren <[email protected]>
>>>>>>>>>>>> wrote:
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> Again look like these are disabled channels. At least chanspec
>>>>>>>>>>>> 0xd022
>>>>>>>>>>>> is 5G channel 34. You say you get this only once so not every 60
>>>>>>>>>>>> seconds?
>>>>>>>>>>> I get this everytime i trigger a reconnect to the wifi
>>>>>>>>>>> network, so
>>>>>>>>>>> not
>>>>>>>>>>> periodically (checked that). Strangely the initial automatic
>>>>>>>>>>> connect
>>>>>>>>>>> doesn't trigger this errors.
>>>>>>>>>> I additionally placed a WARN_ON_ONCE after the error log and
>>>>>>>>>> enabled the
>>>>>>>>>> firmware error log of brcmf_fil_cmd_data(). Maybe this helps.
>>>>>>>>>
>>>>>>>>> It does a bit. At least it shows this is happening with the
>>>>>>>>> dump_survey (again). I don't really understand why though. It
>>>>>>>>> implies
>>>>>>>>> the channel is not disabled, but unclear why. The channel flags are
>>>>>>>>> changed in brcmf_construct_chaninfo() so we probably should focus
>>>>>>>>> debug on that function.
>>>>>>>>
>>>>>>>> i placed a pr_err at the start of brcmf_construct_chaninfo and
>>>>>>>> another
>>>>>>>> pr_err into the for loop before the "if (channel->orig_flags &
>>>>>>>> IEEE80211_CHAN_DISABLED) continue".
>>>>>>>>
>>>>>>>> pr_err("%s: Ch num %d, chanspec 0x%x, orig_flags: %x.\n", __func__,
>>>>>>>> ch.control_ch_num, ch.chspec, channel->orig_flags);
>>>>>>>>
>>>>>>>> It seems that brcmf_construct_chaninfo is called two times, but the
>>>>>>>> results are different. I could find 0xd090 in the first run, but
>>>>>>>> not in
>>>>>>>> second. The other chanspecs doesn't seem to occur in both runs. No
>>>>>>>> idea
>>>>>>>> what's going on here.
>>>>>>>
>>>>>>> Can you print all wiphy band channels before exiting
>>>>>>> brcmf_construct_chaninfo() and print both channel->orig_flags and
>>>>>>> channel->flags?
>>>>>>
>>>>>> Sure. It seems that in the first call of brcmf_construct_chaninfo the
>>>>>> channel 144 is not disabled, but in the second.
>>>>>
>>>>> I am a bit confused. So the chanspec as mentioned in this email
>>>>> subject is no longer observed, but you still see failure in
>>>>> brcmf_set_channel() for other chanspecs?
>>>>
>>>> before we dive deeper into this let me summarize my observations from
>>>> the beginning. From my understanding the errors are triggered for the 5
>>>> GHz channels 34, 38, 42, 46, 144 (chanspec: 0xd022, 0xd026, 0xd02a,
>>>> 0xd090). So i would focus my observations on those.
>>>>
>>>> As you said that the channel flags are set in brcmf_construct_chaninfo()
>>>> i dump them, here is the output of the first call:
>>>>
>>>> [ 8.785850] brcmfmac: 5 GHz: 0: hw_value 34: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 8.785861] brcmfmac: 5 GHz: 2: hw_value 38: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 8.785872] brcmfmac: 5 GHz: 4: hw_value 42: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 8.785882] brcmfmac: 5 GHz: 6: hw_value 46: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 8.785974] brcmfmac: 5 GHz: 23: hw_value 144: orig_flags: 00080000,
>>>> flags 0000011a
>>>>
>>>> All of them except 144 are disabled via flags. Btw wpa_supplicant is
>>>> configured to country DE within the configuration.
>>>>
>>>> The second and last time brcmf_construct_chaninfo() is called is a few
>>>> seconds later during boot, we get the following:
>>>>
>>>> [ 12.490877] brcmfmac: 5 GHz: 0: hw_value 34: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 12.490891] brcmfmac: 5 GHz: 2: hw_value 38: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 12.490904] brcmfmac: 5 GHz: 4: hw_value 42: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 12.490918] brcmfmac: 5 GHz: 6: hw_value 46: orig_flags: 00080000,
>>>> flags 00000001
>>>> [ 12.491031] brcmfmac: 5 GHz: 23: hw_value 144: orig_flags: 00080000,
>>>> flags 00000001
>>>>
>>>> Now all of them are disabled via flags.
>>>>
>>>> So after that i trigger the reconnect to the same 5 GHz network as
>>>> before. brcmf_construct_chaninfo is never called again, but at the time
>>>> brcmf_set_channel is called the flags for these channels are completely
>>>> different:
>>>>
>>>> [ 90.010002] brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail,
>>>> reason -52
>>>> [ 90.010017] brcmfmac: hw_value 34, orig_flags: 00080000, flags
>>>> 00080220
>>>> [ 90.120007] ieee80211 phy0: brcmf_fil_cmd_data: Firmware error: (-20)
>>>> [ 90.120038] brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail,
>>>> reason -52
>>>> [ 90.120053] brcmfmac: hw_value 38, orig_flags: 00080000, flags
>>>> 00080200
>>>> [ 90.230029] ieee80211 phy0: brcmf_fil_cmd_data: Firmware error: (-20)
>>>> [ 90.230058] brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail,
>>>> reason -52
>>>> [ 90.230073] brcmfmac: hw_value 42, orig_flags: 00080000, flags
>>>> 00080200
>>>> [ 90.340042] ieee80211 phy0: brcmf_fil_cmd_data: Firmware error: (-20)
>>>> [ 90.340071] brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail,
>>>> reason -52
>>>> [ 90.340086] brcmfmac: hw_value 46, orig_flags: 00080000, flags
>>>> 00080210
>>>> [ 92.100073] ieee80211 phy0: brcmf_fil_cmd_data: Firmware error: (-20)
>>>> [ 92.100110] brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail,
>>>> reason -52
>>>> [ 92.100126] brcmfmac: hw_value 144, orig_flags: 00080000, flags
>>>> 00080118
>>>>
>>>> Where does these new flags come from? It's clear that these doesn't come
>>>> from brcmf_construct_chaninfo(). So what manipulates the flags
>>>> afterwards? Shouldn't brcmf_construct_chaninfo() called on reconnect?
>>>
>>> I suspect it is not the driver, but net/wireless/reg.c. Could you
>>> define DEBUG in top of that file and build cfg80211.ko with that. Or
>>> if you have CONFIG_DYNAMIC_DEBUG enable debug prints for reg.c through
>>> sysfs [1]
>> Sure, this is a more recent Linux 6.7 and the disconnect is at uptime
>> ~316s followed by the reconnect:
>>
>> [ 0.000000] Booting Linux on physical CPU 0x0
>> [ 0.000000] Linux version 6.7.0-rc6-00022-g55cb5f43689d-dirty
>> (stefanw@stefanw-SCHENKER) (arm-linux-gnueabihf-gcc (GCC) 11.3.1
>> 20220604 [releases/gcc-11 revision
>> 591c0f4b92548e3ae2e8173f4f93984b1c7f62bb], GNU ld
>> (Linaro_Binutils-2022.06) 2.37.20220122) #175 SMP Thu Dec 21 19:15:10
>> CET 2023
>> [ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7),
>> cr=10c5383d
>> [ 0.000000] CPU: div instructions available: patching division code
>> [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing
>> instruction cache
>> [ 0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Plus Rev 1.3
>> ...
>> [ 9.538797] cfg80211: Loading compiled-in X.509 certificates for
>> regulatory database
>> [ 9.699412] usb 1-1.3: USB disconnect, device number 4
>> [ 9.716116] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
>> [ 9.760066] brcmfmac: brcmf_fw_alloc_request: using
>> brcm/brcmfmac43455-sdio for chip BCM4345/6
>> [ 9.770023] cfg80211: loaded regulatory.db is malformed or signature
>> is missing/invalid
>> [ 9.770047] cfg80211: Restoring regulatory settings
>> [ 9.770057] cfg80211: Kicking the queue
>> [ 9.770078] cfg80211: Calling CRDA to update world regulatory domain
>> [ 9.801533] Console: switching to colour dummy device 80x30
>> [ 9.813535] vc4-drm soc:gpu: bound 3f400000.hvs (ops vc4_hvs_ops [vc4])
>> [ 9.816895] vc4-drm soc:gpu: bound 3f902000.hdmi (ops vc4_hdmi_ops [vc4])
>> [ 9.817106] vc4-drm soc:gpu: bound 3f806000.vec (ops vc4_vec_ops [vc4])
>> [ 9.817282] vc4-drm soc:gpu: bound 3f004000.txp (ops vc4_txp_ops [vc4])
>> [ 9.817413] vc4-drm soc:gpu: bound 3f206000.pixelvalve (ops
>> vc4_crtc_ops [vc4])
>> [ 9.817538] vc4-drm soc:gpu: bound 3f207000.pixelvalve (ops
>> vc4_crtc_ops [vc4])
>> [ 9.817745] vc4-drm soc:gpu: bound 3f807000.pixelvalve (ops
>> vc4_crtc_ops [vc4])
>> [ 9.817864] vc4-drm soc:gpu: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4])
>> [ 9.823689] Bluetooth: hci0: BCM: chip id 107
>> [ 9.825669] Bluetooth: hci0: BCM: features 0x2f
>> [ 9.826383] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
>> [ 9.827278] Bluetooth: hci0: BCM4345C0
>> [ 9.827291] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000
>> [ 9.869190] Bluetooth: hci0: BCM4345C0
>> 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch
>> [ 9.915063] Console: switching to colour frame buffer device 240x75
>> [ 9.944429] vc4-drm soc:gpu: [drm] fb0: vc4drmfb frame buffer device
>> [ 9.958353] hub 1-1:1.0: USB hub found
>> [ 9.958412] hub 1-1:1.0: 4 ports detected
>> [ 9.992604] onboard-usb-hub 3f980000.usb:usb-port@1: supply vdd not
>> found, using dummy regulator
>> [ 9.994313] onboard-usb-hub 3f980000.usb:usb-port@1:usb-port@1:
>> supply vdd not found, using dummy regulator
>> [ 9.995590] hub 1-1:1.0: USB hub found
>> [ 9.995690] hub 1-1:1.0: 4 ports detected
>> [ 9.998640] onboard-usb-hub 3f980000.usb:usb-port@1:usb-port@1:
>> supply vdd not found, using dummy regulator
>> [ 10.086053] usbcore: registered new interface driver lan78xx
>> [ 10.094129] brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob
>> available (err=-2)
>> [ 10.098005] 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.135643] cfg80211: Ignoring regulatory request set by core since
>> the driver uses its own custom regulatory domain
>> [ 10.307704] usb 1-1.1: new high-speed USB device number 7 using dwc2
>> [ 10.452108] hub 1-1.1:1.0: USB hub found
>> [ 10.452310] hub 1-1.1:1.0: 3 ports detected
>> [ 10.557660] usb 1-1.3: new low-speed USB device number 8 using dwc2
>> [ 10.726697] input: PixArt Microsoft USB Optical Mouse as
>> /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:045E:00CB.0003/input/input2
>> [ 10.727785] hid-generic 0003:045E:00CB.0003: input: USB HID v1.11
>> Mouse [PixArt Microsoft USB Optical Mouse] on usb-3f980000.usb-1.3/input0
>> [ 10.797638] usb 1-1.1.2: new low-speed USB device number 9 using dwc2
>> [ 10.957069] input: HID 046a:0011 as
>> /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0/0003:046A:0011.0004/input/input3
>> [ 11.019525] hid-generic 0003:046A:0011.0004: input: USB HID v1.11
>> Keyboard [HID 046a:0011] on usb-3f980000.usb-1.1.2/input0
>> [ 11.048402] Bluetooth: hci0: BCM: features 0x2f
>> [ 11.050164] Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+-0190
>> [ 11.050178] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0382
>> [ 11.324175] usb 1-1.1.1: new high-speed USB device number 10 using dwc2
>> [ 11.714298] lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized):
>> No External EEPROM. Setting MAC Speed
>> [ 11.854291] cfg80211: Pending regulatory request, waiting for it to
>> be processed...
>> [ 12.099129] cfg80211: Ignoring regulatory request set by core since
>> the driver uses its own custom regulatory domain
>> [ 12.099161] cfg80211: World regulatory domain updated:
>> [ 12.099168] cfg80211: DFS Master region: unset
>> [ 12.099174] cfg80211: (start_freq - end_freq @ bandwidth),
>> (max_antenna_gain, max_eirp), (dfs_cac_time)
>> [ 12.099189] cfg80211: (755000 KHz - 928000 KHz @ 2000 KHz), (N/A,
>> 2000 mBm), (N/A)
>> [ 12.099201] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 12.099213] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000
>> KHz AUTO), (N/A, 2000 mBm), (N/A)
>> [ 12.099224] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 12.099235] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz,
>> 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
>> [ 12.099248] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz,
>> 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
>> [ 12.099259] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz),
>> (N/A, 2000 mBm), (0 s)
>> [ 12.099269] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 12.099280] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz),
>> (N/A, 0 mBm), (N/A)
>> [ 12.101316] cfg80211: Calling CRDA for country: DE
>> [ 12.125129] cfg80211: Disabling freq 2484.000 MHz
>> [ 12.176440] cfg80211: Regulatory domain changed to country: DE
>> [ 12.176459] cfg80211: DFS Master region: ETSI
>> [ 12.176464] cfg80211: (start_freq - end_freq @ bandwidth),
>> (max_antenna_gain, max_eirp), (dfs_cac_time)
>> [ 12.176473] cfg80211: (2400000 KHz - 2483500 KHz @ 40000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 12.176487] cfg80211: (5150000 KHz - 5250000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 12.176496] cfg80211: (5250000 KHz - 5350000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
>> [ 12.176504] cfg80211: (5470000 KHz - 5725000 KHz @ 160000 KHz),
>> (N/A, 2698 mBm), (0 s)
>> [ 12.176512] cfg80211: (5725000 KHz - 5875000 KHz @ 80000 KHz),
>> (N/A, 1397 mBm), (N/A)
>> [ 12.176521] cfg80211: (5945000 KHz - 6425000 KHz @ 160000 KHz,
>> 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 12.176529] cfg80211: (57000000 KHz - 66000000 KHz @ 2160000 KHz),
>> (N/A, 4000 mBm), (N/A)
>> [ 13.893866] Adding 102396k swap on /var/swap. Priority:-2 extents:1
>> across:102396k SS
>> [ 14.530323] lan78xx 1-1.1.1:1.0 eth0: Link is Down
>> [ 14.641536] Bluetooth: MGMT ver 1.22
>> [ 14.689962] NET: Registered PF_ALG protocol family
>> [ 14.744513] cryptd: max_cpu_qlen set to 1000
>> [ 16.791666] cfg80211: Found new beacon on frequency: 5180.000 MHz (Ch
>> 36) on phy0
>> [ 16.791716] cfg80211: Found new beacon on frequency: 5220.000 MHz (Ch
>> 44) on phy0
>> [ 20.481971] cfg80211: Calling CRDA for country: DE
>> [ 20.501082] cfg80211: Disabling freq 2484.000 MHz
>> [ 20.501465] cfg80211: Regulatory domain changed to country: DE
>> [ 20.501471] cfg80211: DFS Master region: ETSI
>> [ 20.501475] cfg80211: (start_freq - end_freq @ bandwidth),
>> (max_antenna_gain, max_eirp), (dfs_cac_time)
>> [ 20.501490] cfg80211: (2400000 KHz - 2483500 KHz @ 40000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 20.501497] cfg80211: (5150000 KHz - 5250000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 20.501504] cfg80211: (5250000 KHz - 5350000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
>> [ 20.501511] cfg80211: (5470000 KHz - 5725000 KHz @ 160000 KHz),
>> (N/A, 2698 mBm), (0 s)
>> [ 20.501517] cfg80211: (5725000 KHz - 5875000 KHz @ 80000 KHz),
>> (N/A, 1397 mBm), (N/A)
>> [ 20.501524] cfg80211: (5945000 KHz - 6425000 KHz @ 160000 KHz,
>> 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 20.501531] cfg80211: (57000000 KHz - 66000000 KHz @ 2160000 KHz),
>> (N/A, 4000 mBm), (N/A)
>> [ 46.174010] systemd-journald[125]: Failed to set ACL on
>> /var/log/journal/0b443a02fdd340c68f8aac17d2e5ebf8/user-1000.journal,
>> ignoring: Operation not supported
>> [ 84.956286] cfg80211: Verifying active interfaces after reg change
>> [ 128.323869] cfg80211: Found new beacon on frequency: 2472.000 MHz (Ch
>> 13) on phy0
>> [ 192.477390] cfg80211: Verifying active interfaces after reg change
>> [ 316.329988] cfg80211: All devices are disconnected, going to restore
>> regulatory settings
>
> Ok. So here the disconnect happens...
>
>> [ 316.330038] cfg80211: Restoring regulatory settings while preserving
>> user preference for: DE
>> [ 316.330063] cfg80211: Ignoring regulatory request set by core since
>> the driver uses its own custom regulatory domain
>> [ 316.330088] cfg80211: World regulatory domain updated:
>> [ 316.330097] cfg80211: DFS Master region: unset
>> [ 316.330104] cfg80211: (start_freq - end_freq @ bandwidth),
>> (max_antenna_gain, max_eirp), (dfs_cac_time)
>> [ 316.330120] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (600
>> mBi, 2000 mBm), (N/A)
>> [ 316.330140] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000
>> KHz AUTO), (600 mBi, 2000 mBm), (N/A)
>> [ 316.330156] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (600
>> mBi, 2000 mBm), (N/A)
>> [ 316.330172] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz,
>> 160000 KHz AUTO), (600 mBi, 2000 mBm), (N/A)
>> [ 316.330190] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz,
>> 160000 KHz AUTO), (600 mBi, 2000 mBm), (0 s)
>> [ 316.330206] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz),
>> (600 mBi, 2000 mBm), (0 s)
>> [ 316.330222] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (600
>> mBi, 2000 mBm), (N/A)
>> [ 316.330238] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz),
>> (N/A, 0 mBm), (N/A)
>> [ 316.330307] cfg80211: Disabling freq 2484.000 MHz
>> [ 316.340457] cfg80211: Regulatory domain changed to country: DE
>> [ 316.340487] cfg80211: DFS Master region: ETSI
>> [ 316.340495] cfg80211: (start_freq - end_freq @ bandwidth),
>> (max_antenna_gain, max_eirp), (dfs_cac_time)
>> [ 316.340511] cfg80211: (2400000 KHz - 2483500 KHz @ 40000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 316.340529] cfg80211: (5150000 KHz - 5250000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 316.340547] cfg80211: (5250000 KHz - 5350000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
>> [ 316.340563] cfg80211: (5470000 KHz - 5725000 KHz @ 160000 KHz),
>> (N/A, 2698 mBm), (0 s)
>> [ 316.340577] cfg80211: (5725000 KHz - 5875000 KHz @ 80000 KHz),
>> (N/A, 1397 mBm), (N/A)
>> [ 316.340592] cfg80211: (5945000 KHz - 6425000 KHz @ 160000 KHz,
>> 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 316.340607] cfg80211: (57000000 KHz - 66000000 KHz @ 2160000 KHz),
>> (N/A, 4000 mBm), (N/A)
>> [ 316.340643] cfg80211: Kicking the queue
>> [ 331.276421] cfg80211: Found new beacon on frequency: 5180.000 MHz (Ch
>> 36) on phy0
>> [ 331.276494] cfg80211: Found new beacon on frequency: 5220.000 MHz (Ch
>> 44) on phy0
>> [ 331.276562] cfg80211: Found new beacon on frequency: 2472.000 MHz (Ch
>> 13) on phy0
>> [ 332.729896] brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail,
>> reason -52
>> [ 332.840008] brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail,
>> reason -52
>> [ 332.949910] brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail,
>> reason -52
>> [ 333.059802] brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail,
>> reason -52
>> [ 334.819896] brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail,
>> reason -52
>> [ 334.820318] brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail,
>> reason -52
>> [ 334.820719] brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail,
>> reason -52
>> [ 334.821120] brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail,
>> reason -52
>> [ 334.821521] brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail,
>> reason -52
>> [ 334.821922] brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail,
>> reason -52
>
> Do you know if this happens before or after the reconnect has completed?
> You could enable CONN debug level in brcmfmac to determine that.
>
>> [ 334.956787] cfg80211: Calling CRDA for country: DE
>
> I guess this message is a bit stale and there is no crda user-mode helper.
>
>> [ 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. Have you always seen
this or at certain kernel update or wpa_supplicant maybe?
Regards,
Arend
>
> Regards,
> Arend
>
>> [ 334.991199] cfg80211: Regulatory domain changed to country: DE
>> [ 334.991212] cfg80211: DFS Master region: ETSI
>> [ 334.991218] cfg80211: (start_freq - end_freq @ bandwidth),
>> (max_antenna_gain, max_eirp), (dfs_cac_time)
>> [ 334.991236] cfg80211: (2400000 KHz - 2483500 KHz @ 40000 KHz),
>> (N/A, 2000 mBm), (N/A)
>> [ 334.991249] cfg80211: (5150000 KHz - 5250000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 334.991261] cfg80211: (5250000 KHz - 5350000 KHz @ 80000 KHz,
>> 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
>> [ 334.991273] cfg80211: (5470000 KHz - 5725000 KHz @ 160000 KHz),
>> (N/A, 2698 mBm), (0 s)
>> [ 334.991284] cfg80211: (5725000 KHz - 5875000 KHz @ 80000 KHz),
>> (N/A, 1397 mBm), (N/A)
>> [ 334.991296] cfg80211: (5945000 KHz - 6425000 KHz @ 160000 KHz,
>> 480000 KHz AUTO), (N/A, 2301 mBm), (N/A)
>> [ 334.991307] cfg80211: (57000000 KHz - 66000000 KHz @ 2160000 KHz),
>> (N/A, 4000 mBm), (N/A)
>> [ 397.278378] cfg80211: Verifying active interfaces after reg change
Hi Arend,
[add Johannes]
Am 22.12.23 um 16:28 schrieb Arend Van Spriel:
>
>
> On December 22, 2023 4:18:19 PM Arend Van Spriel
> <[email protected]> wrote:
>
>> On December 21, 2023 7:40:46 PM Stefan Wahren <[email protected]> wrote:
>>
>> Do you know if this happens before or after the reconnect has completed?
>> You could enable CONN debug level in brcmfmac to determine that.
before the reconnect
>>
>>> [ 334.956787] cfg80211: Calling CRDA for country: DE
>>
>> I guess this message is a bit stale and there is no crda user-mode
>> helper.
>>
>>> [ 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.
Best regards
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?
johannes
On January 16, 2024 3:09:45 PM Johannes Berg <[email protected]> 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
On Tue, 2024-01-16 at 19:29 +0100, Arend Van Spriel wrote:
> > >
> > > 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?
>
All this confuses me way more than it should, I guess.
We do still have REGULATORY_STRICT_REG, no? And that sets even
orig_flags:
if (lr->initiator == NL80211_REGDOM_SET_BY_DRIVER &&
request_wiphy && request_wiphy == wiphy &&
request_wiphy->regulatory_flags & REGULATORY_STRICT_REG) {
/*
* This guarantees the driver's requested regulatory domain
* will always be used as a base for further regulatory
* settings
*/
chan->flags = chan->orig_flags =
map_regdom_flags(reg_rule->flags) | bw_flags;
But brcmf_construct_chaninfo() looks a bit more like it really should be
setting a custom regulatory with all the channels listed, a bit like
what iwlwifi/mvm does, with REGULATORY_WIPHY_SELF_MANAGED?
Maybe we should start from the beginning: what does this actually
_want_?
johannes