Showing (ath10k) Firmware Load Successes

For Developers
1

The Linux firmware loader happily warns when it can't find one of the many options for firmware load (such as for the ath10k drivers), but never announces when it succeeds.

As I've been caught by misinterpreting the dmesg output myself, I've put together a patch that should clearly indicate success as well. It has been tested against Linux 4.14. I was going to put a PR in for it, but it looks like the structure of the code has changed significantly in Linux 4.19 and its not clear to me yet what the messaging is there.

Edit: Looks like failures for non-existent file (-ENOENT, -2) are no longer warnings in Kernel 4.19. See, for example, https://elixir.bootlin.com/linux/v4.19.35/source/drivers/base/firmware_loader/main.c#L328

In the hopes that it might help someone before I can get Linux 4.19 running and further examine it, give this an appropriate file name and drop into target/linux/generic/pending-4.14/ or the like.

--- a/drivers/base/firmware_class.c
+++ b/drivers/base/firmware_class.c
@@ -1224,9 +1224,20 @@ _request_firmware(const struct firmware
 			dev_warn(device, "Falling back to user helper\n");
 			ret = fw_load_from_user_helper(fw, name, device,
 						       opt_flags);
-		}
-	} else
+			if (!ret && !(opt_flags & FW_OPT_NO_WARN)) {
+				dev_info(device,
+					 "Helper firmware load for %s succeeded\n",
+					 name);
+			};
+		};
+	} else {
+ 		if (!ret && !(opt_flags & FW_OPT_NO_WARN)) {
+			dev_info(device,
+				 "Direct firmware load for %s succeeded\n",
+				 name);
+ 		};
 		ret = assign_firmware_buf(fw, device, opt_flags);
+	};
 
  out:
 	if (ret < 0) {

Here is an example of the output under Linux 4.14.111

[...]
[   10.583243] ath10k 4.19 driver, optimized for CT firmware, probing pci device: 0x56.
[   10.583952] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142)
[   10.590661] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   10.764847] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0000:01:00.0.txt failed with error -2
[   10.765176] ath10k_pci 0000:01:00.0: Falling back to user helper
[   10.812101] firmware ath10k!fwcfg-pci-0000:01:00.0.txt: firmware_loading_store: map pages failed
[   10.812521] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin failed with error -2
[   10.819991] ath10k_pci 0000:01:00.0: Falling back to user helper
[   10.935953] ath10k_pci 0000:01:00.0: Helper firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin succeeded
[   10.940175] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9888/hw2.0/ct-firmware-5.bin failed with error -2
[   10.944587] ath10k_pci 0000:01:00.0: Falling back to user helper
[   10.988251] firmware ath10k!QCA9888!hw2.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   10.988656] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9888/hw2.0/ct-firmware-2.bin failed with error -2
[   10.996605] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.061963] firmware ath10k!QCA9888!hw2.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   11.062345] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9888/hw2.0/firmware-6.bin failed with error -2
[   11.070192] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.127653] firmware ath10k!QCA9888!hw2.0!firmware-6.bin: firmware_loading_store: map pages failed
[   11.434524] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9888/hw2.0/firmware-5.bin succeeded
[   11.434604] ath10k_pci 0000:01:00.0: qca9888 hw2.0 target 0x01000000 chip_id 0x00000000 sub 0000:0000
[   11.443130] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   11.457814] ath10k_pci 0000:01:00.0: firmware ver 10.4b-ct-9888-fW-012-604ef8d6 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT crc32 b1e5658d
[   11.768725] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9888/hw2.0/board-2.bin succeeded
[   11.769078] ath10k_pci 0000:01:00.0: board_file api 2 bmi_id 0:23 crc32 b050e9d6
[   13.798054] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   13.798098] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   13.852565] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   13.853677] ath10k_pci 0000:01:00.0: wmi print 'free: 121760 iram: 26004 sram: 30092'
[   14.076165] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   14.220288] ath: EEPROM regdomain: 0x834b
[   14.220365] ath: EEPROM indicates we should expect a country code
[   14.220452] ath: doing EEPROM country->regdmn map search
[   14.220542] ath: country maps to regdmn code: 0x3a
[   14.220604] ath: Country alpha2 being used: US
[   14.220657] ath: Regpair used: 0x3a
[...]

This does not increase the size of the kernels or builds I examined. Amusingly, it seems as though the kernel compressed better with the patch!

commit e762f5d44a (master)
						    kernel	image
ath79 Archer C7v2 patched	1614527	4064018
ath79 Archer C7v2 stock	    1614723	4064016

ar71xx Archer C7v2 patched	1589046	4063236
ar71xx Archer C7v2 stock	1589105	4063236

Yes, @chunkeey, you've gotten me off on a related tangent again.

2

there is also a patch that hides these fw load failure prints. but it's not yet part of ct driver if i'm correct

2 Likes
3

Dang, can you tell me how that happened? I don't think I ever wrote something about the -2 ENOENT error messages in a sense that they need to be silenced.

That's spot on.I mean we can ask @greearb if he's willing to add that change. But he'll likely ask for the commitid and if turns out to be more work than just cherry-picking then someone needs to make patches for him too.... so you see where this is going.

4

If you want me to make a change, send me a patch and/or a commit-id. I don't care so much if it is upstream or not. If it seems useful, I'll probably add it to the ath10k-ct driver.

5

Not that they needed to be silenced (I didn't interpret that that was a request), but that there was no direct way to determine which firmware/file (if any) had been loaded from kernel messages to confirm proper operation. The best one can do under Linux 4.14 is to know the sequence in which they are checked and look for the absence of an otherwise expected "file not found" error message.

I misinterpreted the logs and my timing measurements in my recent EA8300 work -- it does load from ART fast enough with the patches, thanks! I didn't pursue more than I needed to confirm that the ART data was being extracted in time when I found that the Linux 4.14 patches didn't apply to 4.19.

Linux 4.19 looks like it has addressed a lot of this (and restructured the generic firmware-load code significantly). For example, from drivers/base/firmware_loader/main.c

		rc = kernel_read_file_from_path(path, &fw_priv->data, &size,
						msize, id);
		if (rc) {
			if (rc == -ENOENT)
				dev_dbg(device, "loading %s failed with error %d\n",
					 path, rc);
			else
				dev_warn(device, "loading %s failed with error %d\n",
					 path, rc);
			continue;
		}
		dev_dbg(device, "direct-loading %s\n", fw_priv->fw_name);

Errors in spelling aside, there look to be similar changes in drivers/base/firmware_loader/fallback.c

6

I think we are seeing different things, because the driver announces the loaded firmware (once it booted) in the following way (see last line):

[...]
[   33.691113] ath10k_ahb a800000.wifi: Direct firmware load for ath10k/fwcfg-ahb-a800000.wifi.txt failed with error -2
[   33.691159] ath10k_ahb a800000.wifi: Falling back to user helper
[   34.089375] firmware ath10k!fwcfg-ahb-a800000.wifi.txt: firmware_loading_store: map pages failed
[   34.104868] ath10k_ahb a800000.wifi: Direct firmware load for ath10k/QCA4019/hw1.0/ct-firmware-5.bin failed with error -2
[   34.104923] ath10k_ahb a800000.wifi: Falling back to user helper
[   34.169874] firmware ath10k!QCA4019!hw1.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   34.170164] ath10k_ahb a800000.wifi: Direct firmware load for ath10k/QCA4019/hw1.0/ct-firmware-2.bin failed with error -2
[   34.178177] ath10k_ahb a800000.wifi: Falling back to user helper
[   34.238378] firmware ath10k!QCA4019!hw1.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   34.238737] ath10k_ahb a800000.wifi: Direct firmware load for ath10k/QCA4019/hw1.0/firmware-6.bin failed with error -2
[   34.246681] ath10k_ahb a800000.wifi: Falling back to user helper
[   34.312001] firmware ath10k!QCA4019!hw1.0!firmware-6.bin: firmware_loading_store: map pages failed
[   34.312273] ath10k_ahb a800000.wifi: qca4019 hw1.0 target 0x01000000 chip_id 0x003b00ff sub 0000:0000
[   34.319891] ath10k_ahb a800000.wifi: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   34.332691] ath10k_ahb a800000.wifi: firmware ver 10.4b-ct-4019-fW-012-604ef8d6 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT crc32 b195c9be

The bit I'm always looking for ath10k-ct is firmware ver 10.4b-ct-4019-fW-012-604ef8d6 api 5. That said the standard ath10k also announces the firmware + features in a similar way (but they stick to Qualcomm's version schemata).

Bonus: If you have ethtool installed you can also get that via userspace in the following way:

# ethtool -i wlan1
driver: ath10k_ahb
version: 4.14.109
firmware-version: 10.4b-ct-4019-fW-012-604ef8d6
expansion-rom-version: 
bus-info: a800000.wifi
supports-statistics: yes
supports-test: no
supports-eeprom-access: no
supports-register-dump: no
supports-priv-flags: no
2 Likes
7

this is the commit id: 9f5bcfe93315d75da4cc46bd30b536966559359a

1 Like
8

That patch is in at least my 4.19 and 4.20 drivers. What ath10k-ct driver version are you using?

9

look at jeff's bootlog in first post! too many failed/fallback spam messages makes it harder to spot on loaded fw

10

Much less chatty under Linux 4.19, though still not obvious where the pre-cal file came from (and CRC32 isn't available on the box to check the board file possibilities). It's not clear to me that this is any less confusing to a user that has wireless issues and then, as generally instructed "looks at the logs".

Not asking anyone to "fix" this, just noting some of the remaining challenges.

[    9.558235] ath10k 4.19 driver, optimized for CT firmware, probing pci device: 0x56.
[    9.559013] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142)
[    9.565758] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[    9.776206] firmware ath10k!fwcfg-pci-0000:01:00.0.txt: firmware_loading_store: map pages failed
[    9.964840] firmware ath10k!QCA9888!hw2.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   10.044680] firmware ath10k!QCA9888!hw2.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   10.119551] firmware ath10k!QCA9888!hw2.0!firmware-6.bin: firmware_loading_store: map pages failed
[   11.626269] ath10k_pci 0000:01:00.0: qca9888 hw2.0 target 0x01000000 chip_id 0x00000000 sub 0000:0000
[   11.626316] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   11.639821] ath10k_pci 0000:01:00.0: firmware ver 10.4b-ct-9888-fW-012-604ef8d6 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT crc32 b1e5658d
[   11.951692] ath10k_pci 0000:01:00.0: board_file api 2 bmi_id 0:23 crc32 b050e9d6
[   13.972158] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   13.972200] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   14.026656] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   14.027685] ath10k_pci 0000:01:00.0: wmi print 'free: 121760 iram: 26004 sram: 30092'
[   14.248602] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   14.347632] ath: EEPROM regdomain: 0x834b
[   14.347642] ath: EEPROM indicates we should expect a country code
[   14.347652] ath: doing EEPROM country->regdmn map search
[   14.347661] ath: country maps to regdmn code: 0x3a
[   14.347667] ath: Country alpha2 being used: US
[   14.347672] ath: Regpair used: 0x3a

"map pages failed" reported as kern.err

11

Please take a moment and look at the (pre-)cal ath10k's core.c code:

static int ath10k_fetch_cal_file(struct ath10k *ar)
{
	char filename[100];

	/* pre-cal-<bus>-<id>.bin */
	scnprintf(filename, sizeof(filename), "pre-cal-%s-%s.bin",
		  ath10k_bus_str(ar->hif.bus), dev_name(ar->dev));

	ar->pre_cal_file = ath10k_fetch_fw_file(ar, ATH10K_FW_DIR, filename);
	if (!IS_ERR(ar->pre_cal_file))
		goto success;

	/* cal-<bus>-<id>.bin */
	scnprintf(filename, sizeof(filename), "cal-%s-%s.bin",
		  ath10k_bus_str(ar->hif.bus), dev_name(ar->dev));

	ar->cal_file = ath10k_fetch_fw_file(ar, ATH10K_FW_DIR, filename);
	if (IS_ERR(ar->cal_file))
		/* calibration file is optional, don't print any warnings */
		return PTR_ERR(ar->cal_file);
success:
	ath10k_dbg(ar, ATH10K_DBG_BOOT, "found calibration file %s/%s\n",
		   ATH10K_FW_DIR, filename);

	return 0;
}

and ath10k_fetch_fw_file():

static const struct firmware *ath10k_fetch_fw_file(struct ath10k *ar,
						   const char *dir,
						   const char *file)
{
	char filename[100];
	const struct firmware *fw;
	int ret;

	if (file == NULL)
		return ERR_PTR(-ENOENT);

	if (dir == NULL)
		dir = ".";

	snprintf(filename, sizeof(filename), "%s/%s", dir, file);
	ret = firmware_request_nowarn(&fw, filename, ar->dev);
	ath10k_dbg(ar, ATH10K_DBG_BOOT, "boot fw request '%s': %d\n",
		   filename, ret);

	if (ret)
		return ERR_PTR(ret);

	return fw;
}

The driver has a bunch of debug printk in place that tells what file it tries to load (pre-cal+cal and firmware) and which calibration file it found. But these are all gated behind ATH10K_DBG_BOOT. The driver can be incredibly chatty when the debug_mask ATH10K_DBG_BOOT (0x20 I think) is set, so it's not the default. So what are we going to do there? This is something that's been addressed, but we need to point the people to the right wikis: https://wireless.wiki.kernel.org/en/users/drivers/ath10k/debug where they would find this information.

1 Like