long startup delay ath10k_pci known issue?

long startup delay ath10k_pci known issue?

[Robert White]

I recently switched from an ath9k to an ath10k on my (gentoo based) 
home-build router, and there is about a two minute delay between the 
time of the modprobe of ath10k_pci and the time "iw list" can see the 
wireless endpoint. Then there's maybe another delay before the wlan0 
device appears in the kernel.

This extreme delay is preventing a normal startup because it causes an 
error return in the OpenRC dependency/startup logic.

That dependency tree is it's own problem, of course, but I don't 
understand why the delay is taking place. There are no errors shown in 
the startup and the system runs fine once manually kicked around to get 
it running (e.g. manually modprobing the various devices and then 
waiting and then re-triggering various parts of the startup).

I have to reiterate that the system starts and runs fine as-configured 
if I put the ath9k device back in, so it's not a system-level 
configuration problem.

Is this long delay after module and firmware load some expected effect 
that I need to code around or what?

IF the delay is expected, is there some sort of user-space detectable 
event that I can use to know the de

I built the device by buying a micro PCI card from SparkLan and a 
Chinese PCIexpress adapter card.

The only really weird thing I see is the all-zeros device serial number.


Various Info:

rwhite@lightning ~ $ uname -a
Linux lightning.whiterc.com 4.20.13-gentoo #2 SMP PREEMPT Wed Feb 27 
22:28:03 PST 2019 x86_64 AMD Athlon(tm) II X2 250 Processor AuthenticAMD 
GNU/Linux

[  761.891968] ath10k_pci 0000:03:00.0: limiting irq mode to: 2
[  761.892056] ath10k_pci 0000:03:00.0: pci irq msi oper_irq_mode 2 
irq_mode 2 reset_mode 0
[  947.463173] ath10k_pci 0000:03:00.0: qca988x hw2.0 target 0x4100016c 
chip_id 0x043202ff sub 0000:0000
[  947.463181] ath10k_pci 0000:03:00.0: kconfig debug 0 debugfs 1 
tracing 0 dfs 1 testmode 0
[  947.463787] ath10k_pci 0000:03:00.0: firmware ver 10.2.4-1.0-00043 
api 5 features no-p2p,raw-mode,mfp,allows-mesh-bcast crc32 ed0aafd8
[ 1008.884389] ath10k_pci 0000:03:00.0: board_file api 1 bmi_id N/A 
crc32 bebc7c08
[ 1010.004457] ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
[ 1010.025717] ath10k_pci 0000:03:00.0: htt-ver 2.1 wmi-op 5 htt-op 2 
cal otp max-sta 128 raw 0 hwcrypto 1
[ 1010.088540] ath: EEPROM regdomain: 0x6a
[ 1010.088545] ath: EEPROM indicates we should expect a direct regpair map
[ 1010.088552] ath: Country alpha2 being used: 00
[ 1010.088554] ath: Regpair used: 0x6a
[ 1070.500586] ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
[ 1070.521639] ath10k_pci 0000:03:00.0: pdev param 0 not supported by 
firmware

03:00.0 Network controller: Qualcomm Atheros QCA986x/988x 802.11ac 
Wireless Network Adapter
         Flags: bus master, fast devsel, latency 0, IRQ 35, NUMA node 0
         Memory at fe200000 (64-bit, non-prefetchable) [size=2M]
         Expansion ROM at fe400000 [disabled] [size=64K]
         Capabilities: [40] Power Management version 2
         Capabilities: [50] MSI: Enable+ Count=1/8 Maskable+ 64bit-
         Capabilities: [70] Express Endpoint, MSI 00
         Capabilities: [100] Advanced Error Reporting
         Capabilities: [140] Virtual Channel
         Capabilities: [160] Device Serial Number 00-00-00-00-00-00-00-00
         Kernel driver in use: ath10k_pci
         Kernel modules: ath10k_pci

Re: long startup delay ath10k_pci known issue?

[Kalle Valo]

Robert White <rwhite@pobox.com> writes:

> I recently switched from an ath9k to an ath10k on my (gentoo based)
> home-build router, and there is about a two minute delay between the
> time of the modprobe of ath10k_pci and the time "iw list" can see the
> wireless endpoint. Then there's maybe another delay before the wlan0
> device appears in the kernel.
>
> This extreme delay is preventing a normal startup because it causes an
> error return in the OpenRC dependency/startup logic.
>
> That dependency tree is it's own problem, of course, but I don't
> understand why the delay is taking place. There are no errors shown in
> the startup and the system runs fine once manually kicked around to
> get it running (e.g. manually modprobing the various devices and then
> waiting and then re-triggering various parts of the startup).
>
> I have to reiterate that the system starts and runs fine as-configured
> if I put the ath9k device back in, so it's not a system-level
> configuration problem.

ath9k PCI device does not retrieve firmware images from user space so I
would not yet rule out a system level problem.

> Is this long delay after module and firmware load some expected effect
> that I need to code around or what?

Usually these 60 second (or it's multiply) delays are caused by kernel
requesting a firmware image from user space but the corresponding user
space component is not replying and kernel waits for the reply until it
timeouts and continues. IIRC there's a kernel config option you can use
to disable this feature, or you could also try to fix the user space.

-- 
Kalle Valo

Re: long startup delay ath10k_pci known issue?

[Johannes Berg]

On Thu, 2019-02-28 at 10:37 +0200, Kalle Valo wrote:
> 
> > Is this long delay after module and firmware load some expected effect
> > that I need to code around or what?
> 
> Usually these 60 second (or it's multiply) delays are caused by kernel
> requesting a firmware image from user space but the corresponding user
> space component is not replying and kernel waits for the reply until it
> timeouts and continues. IIRC there's a kernel config option you can use
> to disable this feature, or you could also try to fix the user space.

Regardless though, fixing this will just make the race condition less
likely, not fix it.

Most wifi NICs these days will load firmware because they need to run
it, and they will typically have to load the firmware *before* they
register their wiphy/netdev. Due to technical considerations (built-in
drivers etc.) the firmware load pretty much has to happen
asynchronously.

As a result, modprobe will return before the netdev exists. Now, in your
case you likely have some sort of firmware problem like Kalle says,
which causes it to take an excessive amount of time, perhaps by calling
out to a userspace helper that doesn't work and thus doesn't answer
negatively?

However, the fact remains that you shouldn't assume that modprobe
returning means anything - the netdev will exists when that happens, and
you should trigger your networking startup on the event that says it
exists now.

johannes

long startup delay ath10k_pci known issue?

[Robert White]

I recently switched from an ath9k to an ath10k on my (gentoo based) 
home-build router, and there is about a two minute delay between the 
time of the modprobe of ath10k_pci and the time "iw list" can see the 
wireless endpoint. Then there's maybe another delay before the wlan0 
device appears in the kernel.

This extreme delay is preventing a normal startup because it causes an 
error return in the OpenRC dependency/startup logic.

That dependency tree is it's own problem, of course, but I don't 
understand why the delay is taking place. There are no errors shown in 
the startup and the system runs fine once manually kicked around to get 
it running (e.g. manually modprobing the various devices and then 
waiting and then re-triggering various parts of the startup).

I have to reiterate that the system starts and runs fine as-configured 
if I put the ath9k device back in, so it's not a system-level 
configuration problem.

Is this long delay after module and firmware load some expected effect 
that I need to code around or what?

IF the delay is expected, is there some sort of user-space detectable 
event that I can use to know the de

I built the device by buying a micro PCI card from SparkLan and a 
Chinese PCIexpress adapter card.

The only really weird thing I see is the all-zeros device serial number.


Various Info:

rwhite@lightning ~ $ uname -a
Linux lightning.whiterc.com 4.20.13-gentoo #2 SMP PREEMPT Wed Feb 27 
22:28:03 PST 2019 x86_64 AMD Athlon(tm) II X2 250 Processor AuthenticAMD 
GNU/Linux

[  761.891968] ath10k_pci 0000:03:00.0: limiting irq mode to: 2
[  761.892056] ath10k_pci 0000:03:00.0: pci irq msi oper_irq_mode 2 
irq_mode 2 reset_mode 0
[  947.463173] ath10k_pci 0000:03:00.0: qca988x hw2.0 target 0x4100016c 
chip_id 0x043202ff sub 0000:0000
[  947.463181] ath10k_pci 0000:03:00.0: kconfig debug 0 debugfs 1 
tracing 0 dfs 1 testmode 0
[  947.463787] ath10k_pci 0000:03:00.0: firmware ver 10.2.4-1.0-00043 
api 5 features no-p2p,raw-mode,mfp,allows-mesh-bcast crc32 ed0aafd8
[ 1008.884389] ath10k_pci 0000:03:00.0: board_file api 1 bmi_id N/A 
crc32 bebc7c08
[ 1010.004457] ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
[ 1010.025717] ath10k_pci 0000:03:00.0: htt-ver 2.1 wmi-op 5 htt-op 2 
cal otp max-sta 128 raw 0 hwcrypto 1
[ 1010.088540] ath: EEPROM regdomain: 0x6a
[ 1010.088545] ath: EEPROM indicates we should expect a direct regpair map
[ 1010.088552] ath: Country alpha2 being used: 00
[ 1010.088554] ath: Regpair used: 0x6a
[ 1070.500586] ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
[ 1070.521639] ath10k_pci 0000:03:00.0: pdev param 0 not supported by 
firmware

03:00.0 Network controller: Qualcomm Atheros QCA986x/988x 802.11ac 
Wireless Network Adapter
         Flags: bus master, fast devsel, latency 0, IRQ 35, NUMA node 0
         Memory at fe200000 (64-bit, non-prefetchable) [size=2M]
         Expansion ROM at fe400000 [disabled] [size=64K]
         Capabilities: [40] Power Management version 2
         Capabilities: [50] MSI: Enable+ Count=1/8 Maskable+ 64bit-
         Capabilities: [70] Express Endpoint, MSI 00
         Capabilities: [100] Advanced Error Reporting
         Capabilities: [140] Virtual Channel
         Capabilities: [160] Device Serial Number 00-00-00-00-00-00-00-00
         Kernel driver in use: ath10k_pci
         Kernel modules: ath10k_pci