2024-02-27 08:12:55

by Harald Dunkel

[permalink] [raw]
Subject: "iwlwifi: probe of 0000:00:14.3 failed with error -22"

Hi folks,

The Intel Wifi hardware of a colleague's Tuxedo laptop (running Debian 12,
kernel 6.1.76) isn't found at boot time anymore. It doesn't come back on a
reboot. The kernel log shows

[Mon Feb 26 13:21:23 2024] Intel(R) Wireless WiFi driver for Linux
[Mon Feb 26 13:21:23 2024] RAPL PMU: API unit is 2^-32 Joules, 3 fixed counters, 655360 ms ovfl timer
[Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
[Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: Adding cdb to rf id
[Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: Detected RF 0x1010c000 from crf id 0x504
[Mon Feb 26 13:21:23 2024] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
[Mon Feb 26 13:21:23 2024] iwlwifi: probe of 0000:00:14.3 failed with error -22

Please note the last 3 lines. rfkill doesn't list wireless.

On another Tuxedo laptop with the same hardware (AFAICT) we get

[Tue Feb 27 07:35:34 2024] Intel(R) Wireless WiFi driver for Linux
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: firmware: direct-loading firmware iwlwifi-so-a0-hr-b0-72.ucode
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: api flags index 2 larger than supported by driver
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: TLV_FW_FSEQ_VERSION: FSEQ Version: 0.0.2.36
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: firmware: failed to load iwl-debug-yoyo.bin (-2)
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: firmware: failed to load iwl-debug-yoyo.bin (-2)
[Tue Feb 27 07:35:34 2024] iwlwifi 0000:00:14.3: loaded firmware version 72.daa05125.0 so-a0-hr-b0-72.ucode op_mode iwlmvm
:
[Tue Feb 27 07:35:35 2024] iwlwifi 0000:00:14.3: Detected Intel(R) Wi-Fi 6 AX201 160MHz, REV=0x370
:
[Tue Feb 27 07:35:35 2024] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100
:
[Tue Feb 27 07:35:36 2024] iwlwifi 0000:00:14.3: base HW address: e4:0d:xx:xx:xx:xx


Upgrading the kernel to Debian's backports version 6.5.7 doesn't help.
No wifi. I had upgraded the firmware file to version 83 as well, but this
is moot if the firmware isn't loaded at all.


Every helpful comment is highly appreciated

Harri


2024-02-27 09:21:30

by Johannes Berg

[permalink] [raw]
Subject: Re: "iwlwifi: probe of 0000:00:14.3 failed with error -22"

On Tue, 2024-02-27 at 09:12 +0100, Harald Dunkel wrote:
> The Intel Wifi hardware of a colleague's Tuxedo laptop (running Debian 12,
> kernel 6.1.76) isn't found at boot time anymore. It doesn't come back on a
> reboot. The kernel log shows
>
> [Mon Feb 26 13:21:23 2024] Intel(R) Wireless WiFi driver for Linux
> [Mon Feb 26 13:21:23 2024] RAPL PMU: API unit is 2^-32 Joules, 3 fixed counters, 655360 ms ovfl timer
> [Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
> [Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: Adding cdb to rf id
> [Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: Detected RF 0x1010c000 from crf id 0x504
> [Mon Feb 26 13:21:23 2024] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
> [Mon Feb 26 13:21:23 2024] iwlwifi: probe of 0000:00:14.3 failed with error -22

Are you saying that it used to work with that same kernel, or are you
saying that it worked with an older kernel?

In either case, do you have a working log?

If you really have subdevice ID 0000 then something went wrong and you
have a blank OTP (now), which seems very strange.

This is an integrated NIC where part of the NIC is integrated into the
platform, and other parts are on the companion RF (CRF), so could also
be that the CRF module isn't seated well any more in the slot and it
just cannot access the data properly?

johannes

2024-02-28 10:23:22

by Harald Dunkel

[permalink] [raw]
Subject: Re: "iwlwifi: probe of 0000:00:14.3 failed with error -22"

On 2024-02-27 10:21:13, Johannes Berg wrote:
> On Tue, 2024-02-27 at 09:12 +0100, Harald Dunkel wrote:
>> The Intel Wifi hardware of a colleague's Tuxedo laptop (running Debian 12,
>> kernel 6.1.76) isn't found at boot time anymore. It doesn't come back on a
>> reboot. The kernel log shows
>>
>> [Mon Feb 26 13:21:23 2024] Intel(R) Wireless WiFi driver for Linux
>> [Mon Feb 26 13:21:23 2024] RAPL PMU: API unit is 2^-32 Joules, 3 fixed counters, 655360 ms ovfl timer
>> [Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
>> [Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: Adding cdb to rf id
>> [Mon Feb 26 13:21:23 2024] iwlwifi 0000:00:14.3: Detected RF 0x1010c000 from crf id 0x504
>> [Mon Feb 26 13:21:23 2024] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
>> [Mon Feb 26 13:21:23 2024] iwlwifi: probe of 0000:00:14.3 failed with error -22
>
> Are you saying that it used to work with that same kernel, or are you
> saying that it worked with an older kernel?
>

It used to work with the same kernel. We had configured 5 identical laptops
in the office, including wifi. After some time this one laptop showed the
problem. AFAIU it crashed first, but I have no records about this.

My colleague turned off the laptop for a power off reset over night (if this
is possible for a laptop with a batter). Next morning Wifi was back. Seems
to be some reset issue.

> In either case, do you have a working log?
>

This is what we get for the new (6.5.10, Debian backports) kernel now:

```
root@ppcl013:~# dmesg -T | egrep -i wifi\|00:14.3
[Tue Feb 27 09:43:54 2024] pci 0000:00:14.3: [8086:51f1] type 00 class 0x028000
[Tue Feb 27 09:43:54 2024] pci 0000:00:14.3: reg 0x10: [mem 0x601d174000-0x601d177fff 64bit]
[Tue Feb 27 09:43:54 2024] pci 0000:00:14.3: PME# supported from D0 D3hot D3cold
[Tue Feb 27 09:43:54 2024] pci 0000:00:14.3: Adding to iommu group 8
[Tue Feb 27 09:44:51 2024] Intel(R) Wireless WiFi driver for Linux
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: Detected crf-id 0x1300504, cnv-id 0x80400 wfpm id 0x80000030
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: firmware: direct-loading firmware iwlwifi-so-a0-hr-b0-83.ucode
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: api flags index 2 larger than supported by driver
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: TLV_FW_FSEQ_VERSION: FSEQ Version: 0.0.2.41
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: firmware: failed to load iwl-debug-yoyo.bin (-2)
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: firmware: failed to load iwl-debug-yoyo.bin (-2)
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: loaded firmware version 83.e8f84e98.0 so-a0-hr-b0-83.ucode op_mode iwlmvm
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: Detected Intel(R) Wi-Fi 6 AX201 160MHz, REV=0x370
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: WRT: Invalid buffer destination
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: WFPM_UMAC_PD_NOTIFICATION: 0x20
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: WFPM_AUTH_KEY_0: 0x90
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: CNVI_SCU_SEQ_DATA_DW9: 0x10
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: RFIm is deactivated, reason = 4
[Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: base HW address: e4:0d:xx:xx:xx:xx
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WRT: Invalid buffer destination
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WFPM_UMAC_PD_NOTIFICATION: 0x20
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WFPM_AUTH_KEY_0: 0x90
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: CNVI_SCU_SEQ_DATA_DW9: 0x10
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: RFIm is deactivated, reason = 4
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: Registered PHC clock: iwlwifi-PTP, with index: 0
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WRT: Invalid buffer destination
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WFPM_UMAC_PD_NOTIFICATION: 0x20
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: WFPM_AUTH_KEY_0: 0x90
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: CNVI_SCU_SEQ_DATA_DW9: 0x10
[Tue Feb 27 09:44:52 2024] iwlwifi 0000:00:14.3: RFIm is deactivated, reason = 4
[Tue Feb 27 09:47:12 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
[Tue Feb 27 09:47:12 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
[Tue Feb 27 09:47:12 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
[Wed Feb 28 09:47:03 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
[Wed Feb 28 09:47:03 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
[Wed Feb 28 09:47:03 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
[Wed Feb 28 09:47:03 2024] iwlwifi 0000:00:14.3: Unhandled alg: 0x703
```

Hope this helps.

> If you really have subdevice ID 0000 then something went wrong and you
> have a blank OTP (now), which seems very strange.
>
> This is an integrated NIC where part of the NIC is integrated into the
> platform, and other parts are on the companion RF (CRF), so could also
> be that the CRF module isn't seated well any more in the slot and it
> just cannot access the data properly?
>

You mean there could be a problem with the wifi card not being plugged in
properly? We will check when my colleague is in the office.


Regards
Harri

2024-02-28 10:31:36

by Johannes Berg

[permalink] [raw]
Subject: Re: "iwlwifi: probe of 0000:00:14.3 failed with error -22"

On Wed, 2024-02-28 at 11:23 +0100, Harald Dunkel wrote:

> It used to work with the same kernel.

OK.

> This is what we get for the new (6.5.10, Debian backports) kernel now:

But that'd mean it's working - or are you saying that's a different
machine?

> [Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
> [Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: Detected crf-id 0x1300504, cnv-id 0x80400 wfpm id 0x80000030
> [Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100

This seems to work, has a proper PCI ID, and shows a different RF ID?

You previously showed

iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000

So I think it'd still be interesting to know this line from the system
that doesn't work any more, to see if it really was _exactly_ the same,
as this before and changed, or whatever happened.


> > If you really have subdevice ID 0000 then something went wrong and you
> > have a blank OTP (now), which seems very strange.
> >
> > This is an integrated NIC where part of the NIC is integrated into the
> > platform, and other parts are on the companion RF (CRF), so could also
> > be that the CRF module isn't seated well any more in the slot and it
> > just cannot access the data properly?
> >
>
> You mean there could be a problem with the wifi card not being plugged in
> properly? We will check when my colleague is in the office.

Yes, that's what I mean.

Note the "wifi card" is just the CRF module in this case, much of the
wifi is already built into the platform/SoC. The M.2 form factor card
that you have in it isn't the PCIe device that shows up in Linux, it's
just the radio module etc. So that not being connected properly might
explain a situation like this, not sure though.

johannes

2024-02-29 14:46:07

by Harald Dunkel

[permalink] [raw]
Subject: Re: "iwlwifi: probe of 0000:00:14.3 failed with error -22"

Hi Johannes,

On 2024-02-28 11:30:44, Johannes Berg wrote:
> On Wed, 2024-02-28 at 11:23 +0100, Harald Dunkel wrote:
>
>> It used to work with the same kernel.
>
> OK.
>
>> This is what we get for the new (6.5.10, Debian backports) kernel now:
>
> But that'd mean it's working - or are you saying that's a different
> machine?
>

The laptop recovered on a power off reset over night. It worked again
on the next morning (I was told). I logged in via VPN to upgrade kernel
and ucode file. My colleague rebooted it once again, and it is still
working.


>> [Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
>> [Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: Detected crf-id 0x1300504, cnv-id 0x80400 wfpm id 0x80000030
>> [Tue Feb 27 09:44:51 2024] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
>
> This seems to work, has a proper PCI ID, and shows a different RF ID?
>

Yes, I would say so.

> You previously showed
>
> iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
>
> So I think it'd still be interesting to know this line from the system
> that doesn't work any more, to see if it really was _exactly_ the same,
> as this before and changed, or whatever happened.
>

root@ppcl013:~# grep rfid /var/log/kern.log
2024-02-26T09:55:24.858020+01:00 ppcl013 kernel: [ 82.527151] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
2024-02-26T13:21:24.361666+01:00 ppcl013 kernel: [ 20.136735] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
2024-02-26T15:30:25.639827+01:00 ppcl013 kernel: [ 38.203931] iwlwifi 0000:00:14.3: PCI dev 51f1/0000, rev=0x370, rfid=0x3010a100
2024-02-26T15:30:25.639828+01:00 ppcl013 kernel: [ 38.204862] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x3010a100
2024-02-26T20:45:28.752692+01:00 ppcl013 kernel: [ 21.294757] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
2024-02-26T20:45:28.752723+01:00 ppcl013 kernel: [ 21.813877] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100
2024-02-27T09:11:49.132498+01:00 ppcl013 kernel: [ 48.939136] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
2024-02-27T09:11:49.132582+01:00 ppcl013 kernel: [ 49.420458] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100
2024-02-27T09:44:52.740746+01:00 ppcl013 kernel: [ 57.435249] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
2024-02-27T09:44:52.740759+01:00 ppcl013 kernel: [ 57.764033] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100

>
>>> If you really have subdevice ID 0000 then something went wrong and you
>>> have a blank OTP (now), which seems very strange.
>>>
>>> This is an integrated NIC where part of the NIC is integrated into the
>>> platform, and other parts are on the companion RF (CRF), so could also
>>> be that the CRF module isn't seated well any more in the slot and it
>>> just cannot access the data properly?
>>>
>>
>> You mean there could be a problem with the wifi card not being plugged in
>> properly? We will check when my colleague is in the office.
>
> Yes, that's what I mean.
>

We will check when my colleague is back from home office, but this
might take some time.


Regards

Harri

2024-02-29 15:02:53

by Johannes Berg

[permalink] [raw]
Subject: Re: "iwlwifi: probe of 0000:00:14.3 failed with error -22"

Hi Harald,

> The laptop recovered on a power off reset over night. It worked again
> on the next morning (I was told). I logged in via VPN to upgrade kernel
> and ucode file. My colleague rebooted it once again, and it is still
> working.

Fun :)

Well also good I guess. No idea what could have happened though.

> root@ppcl013:~# grep rfid /var/log/kern.log
> 2024-02-26T09:55:24.858020+01:00 ppcl013 kernel: [ 82.527151] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
> 2024-02-26T13:21:24.361666+01:00 ppcl013 kernel: [ 20.136735] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x1010c000
> 2024-02-26T15:30:25.639827+01:00 ppcl013 kernel: [ 38.203931] iwlwifi 0000:00:14.3: PCI dev 51f1/0000, rev=0x370, rfid=0x3010a100
> 2024-02-26T15:30:25.639828+01:00 ppcl013 kernel: [ 38.204862] iwlwifi: No config found for PCI dev 51f1/0000, rev=0x370, rfid=0x3010a100
> 2024-02-26T20:45:28.752692+01:00 ppcl013 kernel: [ 21.294757] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
> 2024-02-26T20:45:28.752723+01:00 ppcl013 kernel: [ 21.813877] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100
> 2024-02-27T09:11:49.132498+01:00 ppcl013 kernel: [ 48.939136] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
> 2024-02-27T09:11:49.132582+01:00 ppcl013 kernel: [ 49.420458] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100
> 2024-02-27T09:44:52.740746+01:00 ppcl013 kernel: [ 57.435249] iwlwifi 0000:00:14.3: PCI dev 51f1/0074, rev=0x370, rfid=0x10a100
> 2024-02-27T09:44:52.740759+01:00 ppcl013 kernel: [ 57.764033] iwlwifi 0000:00:14.3: Detected RF HR B3, rfid=0x10a100

That's interesting though because at one point it bound to it properly,
but still had a 0000 PCI ID and the (likely wrong) RFID 0x3010a100, vs.
most of the working cases have 0074 PCI ID and 0x10a100 RFID.

So looks like something is not quite stable with this system, but it
still worked most of the time!

> We will check when my colleague is back from home office, but this
> might take some time.

Sure. Seems to work now, so at least that's good, I guess.

I still think this might be an issue here, or maybe the CRF is just
flaky somehow? Don't have any experience with these kind of issues
either, TBH.

Anyway, glad it works again.

johannes