pipcet / pearl

GNU/Linux on Apple M1 hardware
GNU General Public License v3.0
35 stars 6 forks source link

M1 Mini - Boot persistence #31

Open Johnnie390 opened 2 years ago

Johnnie390 commented 2 years ago

Pip,

as discussed in thread/issue #29. I would like to know when boot persistance might become available on this hardware using an NVME SSD. As I am not familiar with apple internals or this stage1/2/3 stuff, being a humble Linux soldier. Any assistance you need, please let me know.

Regards,

Ry

PS I have booted to RAM in the past using tmpfs and initramfs, but as stated already, I am not familiar with apple's walled garden.

Johnnie390 commented 2 years ago

As requested, output of tar tvf /persist/wifi.tar. wifi.txt

pipcet commented 2 years ago

Still no luck.

Can you try copying /lib/firmware/brcm/brcmfmac4378-pcie.apple,j293.txt to /lib/firmware/brcm/brcmfmac4378-pcie.apple,j274.txt and reloading the driver a few times?

pipcet commented 2 years ago

Hmm. I think we really need to try with the specific files from wifi.tar:

honshu.txcb becomes brcmfmac4378-pcie.txcb.

honshu.trx becomes brcmfmac4378-pcie.apple,j274.bin

honshu.clmb becomes brcmfmac4378-pcie.clm_blob

P-honshu_M-RASP_V-m__m-6.11.txt becomes brcmfmac4378-pcie.apple,j274.txt

Delete (or move out of the way) all other files in /lib/firmware/brcm.

Johnnie390 commented 2 years ago

Pip,

are you sure?

On macos (Mini M1) this morning, "ioreg -l | grep RequestedFiles" reported - "RequestedFiles" = ({"Firmware"="C-4378s-B1/atlantisb.trx","TxCap"="C-4378s-B1/atlantisb-X3.txcb","Regulatory"="C-4378s-B1/atlantisb-X3.clmb","NVRAM"="C-4378s-B1/P-atlantisb-X3_M-RASP_V-m__m-6.11.txt"})

Ry

pipcet commented 2 years ago

Oh! That might be it :-)

Johnnie390 commented 2 years ago

However, instead of using the instructions and naming conventions here - https://wiki.t2linux.org/guides/wifi/.

I will use yours.

PS It is somewhat confusing to know what "naming convention" is correct with uppercase, lowercase, spaces etc. See here https://wiki.t2linux.org/guides/wifi/.

Ry

pipcet commented 2 years ago

Apple has its own naming conventions, and the Linux kernel driver has at least two separate ones. I have no preference in particular :-)

I think you need to replace brcmfmac4378-pcie.txcb with the 304-byte atlantisb.txcb from wifi.tar.

Looking over my script now, it seems I hardcoded the honshu assumption. Going to fix that in a minute, and then ideally brcmfmac should just work (but tg3 still requires the unbind-bind dance until I figure out how to delay its initialization until after the IOMMUs are up).

Johnnie390 commented 2 years ago

Pip,

contents of /lib/firmware/brcm -

root@magalas:/Transit# ll /lib/firmware/brcm/ total 2568 4 drwxr-xr-x 2 root root 4096 Dec 25 12:44 . 4 drwxrwxrwx 33 root root 4096 Dec 24 15:23 .. 1256 -rw-r--r-- 1 root root 1282925 Sep 21 08:35 brcmfmac4378-pcie.apple,j274.bin 8 -rw-r--r-- 1 root root 7666 Sep 21 08:35 brcmfmac4378-pcie.apple,j274.txt 1256 -rw-r--r-- 1 root root 1282925 Sep 21 08:35 brcmfmac4378-pcie.bin 36 -rw-r--r-- 1 root root 33493 Sep 21 08:35 brcmfmac4378-pcie.clm_blob 4 -rw-r--r-- 1 root root 304 Sep 21 08:35 brcmfmac4378-pcie.txcb

modprobe -r brcmfmac && modprobe brcmfmac or rmmod brcmfmac brcmutil && sleep 2 && modprobe brcmfmac nvram_mac_addr=161616161616

still results in -

Sat Dec 25 12:45:11 2021] cfg80211: Loading compiled-in X.509 certificates for regulatory database [Sat Dec 25 12:45:11 2021] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [Sat Dec 25 12:45:11 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sat Dec 25 12:45:11 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sat Dec 25 12:45:11 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sat Dec 25 12:45:11 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sat Dec 25 12:45:18 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize

pipcet commented 2 years ago

brcmfmac4378-pcie.apple,j274.bin isn't from wifi.tar, is it?

Johnnie390 commented 2 years ago

Pip, I am confused now. According to this article - https://wiki.t2linux.org/guides/wifi/

Renaming Firmware¶

Rename the .trx "Firmware" file to brcmfmac4364-pcie.bin, but change 4364 to your wifi chipset number.
Do the same for the .clmb "Regulatory" file and rename it to brcmfmac4364-pcie.clm_blob. Again, change 4364 to your chipset number.
Lastly, rename the .txt "NVRAM" file to brcmfmac4364-pcie.Apple Inc.-MacBookPro15,1.txt but in addition to changing 4364 to your chipset number, change MacBookPro15,1 to your Model Identifier.

Perhaps we should start with a clean slate, i.e. start with the wifi part from scratch.

pipcet commented 2 years ago

Okay, how about this: start by deleting/renaming /lib/firmware/brcm mkdir /lib/firmware/brcm unpack wifi.tar from .../usr/share/firmware/wifi/C-4378__s-B1, do

cp P-atlantisb_M-*6.11.txt /lib/firmware/brcm/brcmfmac4378-pcie.txt
cp atlantisb.trx /lib/firmware/brcm/brcmfmac4378-pcie.apple,j274.bin
cp atlantisb.txcb /lib/firmware/brcm/brcmfmac4378-pcie.txcb
cp atlantisb.clmb /lib/firmware/brcm/brcmfmac4378-pcie.clm_blob

Confirm your /lib/firmware/brcm looks like this:

total 1364
-rw-r--r-- 1 root root 1345130 Dec 25 08:13 brcmfmac4378-pcie.apple,j274.bin
-rw-r--r-- 1 root root   33493 Dec 25 08:14 brcmfmac4378-pcie.clm_blob
-rw-r--r-- 1 root root     304 Dec 25 08:13 brcmfmac4378-pcie.txcb
-rw-r--r-- 1 root root    7666 Dec 25 08:13 brcmfmac4378-pcie.txt

Then try unloading and reloading the brcmfmac module. I get:

[12207.912904] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[12208.018990] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[12208.018999] brcmfmac 0000:01:00.0: module serial number: 0c0XXXXXXXXXXX
[12208.019069] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[12208.019582] brcmfmac 0000:01:00.0: Direct firmware load for brcm/brcmfmac4378-pcie.apple,j274.txt failed with error -2
[12208.019587] brcmfmac 0000:01:00.0: Falling back to sysfs fallback for: brcm/brcmfmac4378-pcie.apple,j274.txt
[12208.672813] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[12208.687781] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4378/3 wl0: Oct 26 2021 16:10:41 version 18.20.310.15.7.8.120 FWID 01-5d6c3867
[12208.740676] brcmfmac 0000:01:00.0 wlp1s0f0: renamed from wlan0
[12209.449355] ieee80211 phy14: brcmf_p2p_set_firmware: failed to update device address ret -52
[12209.449651] ieee80211 phy14: brcmf_p2p_create_p2pdev: set p2p_disc error
[12209.449656] ieee80211 phy14: brcmf_cfg80211_add_iface: add iface p2p-dev-wlp1s0f type 10 failed: err=-52
[12217.645252] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0f0: link becomes ready
Johnnie390 commented 2 years ago

Pip,

oot@magalas:/Transit# ll /lib/firmware/brcm total 1372 4 drwxr-xr-x 2 root root 4096 Dec 25 15:46 . 4 drwxrwxrwx 34 root root 4096 Dec 25 15:42 .. 1316 -rw-r--r-- 1 root root 1345130 Dec 25 15:46 brcmfmac4378-pcie.apple,j274.bin 36 -rw-r--r-- 1 root root 33493 Dec 25 15:46 brcmfmac4378-pcie.clm_blob 4 -rw-r--r-- 1 root root 304 Dec 25 15:46 brcmfmac4378-pcie.txcb 8 -rw-r--r-- 1 root root 7666 Dec 25 15:45 brcmfmac4378-pcie.txt

Unfortunately -

[Sat Dec 25 15:49:52 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sat Dec 25 15:49:52 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sat Dec 25 15:49:52 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sat Dec 25 15:49:52 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sat Dec 25 15:49:52 2021] brcmfmac 0000:01:00.0: Direct firmware load for brcm/brcmfmac4378-pcie.apple,j274.txt failed with error -2 [Sat Dec 25 15:49:52 2021] brcmfmac 0000:01:00.0: Falling back to sysfs fallback for: brcm/brcmfmac4378-pcie.apple,j274.txt [Sat Dec 25 15:49:58 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize

Ry

Johnnie390 commented 2 years ago

root@magalas:/Transit# modprobe -vv brcmfmac modprobe: INFO: ../libkmod/libkmod.c:367 kmod_set_log_fn() custom logging function 0xaaaac21ac580 registered insmod /lib/modules/5.16.0-rc6/kernel/drivers/net/wireless/broadcom/brcm80211/brcmutil/brcmutil.ko insmod /lib/modules/5.16.0-rc6/kernel/drivers/net/wireless/broadcom/brcm80211/brcmfmac/brcmfmac.ko nvram_mac_addr=16E296D190B3 modprobe: INFO: ../libkmod/libkmod.c:334 kmod_unref() context 0xaaaaff3d4570 released

pipcet commented 2 years ago

I'll have to think about this for a bit. The firmware you're using probably isn't the problem at this point, so I wonder whether this might be an interrupt issue again... It's odd I'm unable to reproduce this as our hardware setups are fairly similar.

pipcet commented 2 years ago

Okay, I checked, and the code in question doesn't use interrupts.

I've just triggered a release which builds, and loads the driver, with debug information enabled. It'd be great if you could try that and have a look at sudo dmesg; there shouldn't be very many lines from the brcmfmac driver after a reboot, probably just three repeats of "wait for FW init", then "FW failed to initialize" five seconds later.

Johnnie390 commented 2 years ago

Here we are -

[Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_exit Enter [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_register Enter [Sun Dec 26 06:43:23 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff800012638000 base addr 0x000006c0c00000 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800021800000 base addr 0x000006c0000000 size 0x800000 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' [Sun Dec 26 06:43:23 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sun Dec 26 06:43:23 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) [Sun Dec 26 06:43:23 2021] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init [Sun Dec 26 06:43:29 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize

Most likely related to your debug change. Also appearing with an insmod/modprobe -

root@magalas:/Transit# modprobe -vv brcmfmac modprobe: INFO: ../libkmod/libkmod.c:367 kmod_set_log_fn() custom logging function 0xaaaab43cc580 registered insmod /lib/modules/5.16.0-rc6/kernel/drivers/net/wireless/broadcom/brcm80211/brcmfmac/brcmfmac.ko nvram_mac_addr=169E54395052' debug=524288' modprobe: INFO: ../libkmod/libkmod-module.c:892 kmod_module_insert_module() Failed to insert module '/lib/modules/5.16.0-rc6/kernel/drivers/net/wireless/broadcom/brcm80211/brcmfmac/brcmfmac.ko': Invalid argument modprobe: ERROR: could not insert 'brcmfmac': Invalid argument modprobe: INFO: ../libkmod/libkmod.c:334 kmod_unref() context 0xaaaabdee4570 released

The "Invalid argument" above is referring to this - brcmfmac: 524288'' invalid for parameterdebug' methinks

Update, brcm palaver from syslog this morning, as requested Dec 26 06:37:25 magalas kernel: [ 17.653517] cfg80211: Loading compiled-in X.509 certificates for regulatory database Dec 26 06:37:25 magalas kernel: [ 17.654327] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Dec 26 06:37:25 magalas kernel: [ 17.654716] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 Dec 26 06:37:25 magalas kernel: [ 17.655103] platform regulatory.0: Falling back to sysfs fallback for: regulatory.db Dec 26 06:37:25 magalas kernel: [ 17.655938] brcmfmac: brcmf_pcie_register Enter Dec 26 06:37:25 magalas kernel: [ 17.656041] brcmfmac 0000:01:00.0: Adding to iommu group 5 Dec 26 06:37:25 magalas kernel: [ 17.656635] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 Dec 26 06:37:25 magalas kernel: [ 17.657020] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 Dec 26 06:37:25 magalas kernel: [ 17.657029] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002) Dec 26 06:37:25 magalas kernel: [ 17.657445] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff800012608000 base addr 0x000006c0c00000 Dec 26 06:37:25 magalas kernel: [ 17.657447] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800021800000 base addr 0x000006c0000000 size 0x800000 Dec 26 06:37:25 magalas kernel: [ 17.765741] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' Dec 26 06:37:25 magalas kernel: [ 17.765744] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' Dec 26 06:37:25 magalas kernel: [ 17.765745] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' Dec 26 06:37:25 magalas kernel: [ 17.765745] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' Dec 26 06:37:25 magalas kernel: [ 17.765746] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' Dec 26 06:37:25 magalas kernel: [ 17.765747] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m Dec 26 06:37:25 magalas kernel: [ 17.766169] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 Dec 26 06:37:25 magalas kernel: [ 17.766611] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 Dec 26 06:37:25 magalas kernel: [ 17.767567] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. Dec 26 06:37:25 magalas kernel: [ 17.767570] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a Dec 26 06:37:25 magalas kernel: [ 18.055216] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 Dec 26 06:37:25 magalas kernel: [ 18.056988] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) Dec 26 06:37:25 magalas kernel: [ 18.057099] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init Dec 26 06:37:25 magalas kernel: [ 18.413265] brcmfmac: brcmf_pcie_download_fw_nvram Shared RAM addr: 0x004cacd0 Dec 26 06:37:25 magalas kernel: [ 18.413268] brcmfmac: brcmf_pcie_init_share_ram_info PCIe protocol version 7 Dec 26 06:37:25 magalas kernel: [ 18.413276] brcmfmac: brcmf_pcie_init_share_ram_info max rx buf post 575, rx dataoffset 0 Dec 26 06:37:25 magalas kernel: [ 18.413315] brcmfmac: brcmf_pcie_init_ringbuffers Using host memory indices Dec 26 06:37:25 magalas kernel: [ 18.413344] brcmfmac: brcmf_pcie_init_ringbuffers Nr of flowrings is 40 Dec 26 06:37:25 magalas kernel: [ 18.414442] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 511 (0), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.414445] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING ! Dec 26 06:37:25 magalas kernel: [ 18.414446] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.433264] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.453263] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.473265] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.493266] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.513263] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.533263] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.553263] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.573263] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.593263] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 0 (511), ring 1 Dec 26 06:37:25 magalas kernel: [ 18.613279] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 8 (0), ring 0 Dec 26 06:37:25 magalas kernel: [ 18.613281] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING ! Dec 26 06:37:25 magalas kernel: [ 18.613298] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 16 (0), ring 0 Dec 26 06:37:25 magalas kernel: [ 18.613299] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING ! Dec 26 06:37:25 magalas kernel: [ 18.613300] brcmfmac: brcmf_pcie_request_irq Enter Dec 26 06:37:25 magalas kernel: [ 18.613414] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 17 (0), ring 0 Dec 26 06:37:25 magalas kernel: [ 18.613415] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING ! Dec 26 06:37:25 magalas kernel: [ 20.637268] ieee80211 phy0: brcmf_msgbuf_query_dcmd: Timeout on response for query command Dec 26 06:37:25 magalas kernel: [ 20.637740] ieee80211 phy0: brcmf_c_preinit_dcmds: Retrieving cur_etheraddr failed, -5 Dec 26 06:37:25 magalas kernel: [ 20.638207] ieee80211 phy0: brcmf_bus_started: failed: -5 Dec 26 06:37:25 magalas kernel: [ 20.638681] ieee80211 phy0: brcmf_attach_postirq: dongle is not responding: err=-5 Dec 26 06:37:25 magalas kernel: [ 20.653891] brcmfmac: brcmf_pcie_remove Enter Dec 26 06:37:25 magalas kernel: [ 23.775153] brcmfmac: brcmf_pcie_exit Enter Dec 26 06:37:25 magalas kernel: [ 23.795744] brcmfmac: brcmf_pcie_register Enter Dec 26 06:37:25 magalas kernel: [ 23.795780] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 Dec 26 06:37:25 magalas kernel: [ 23.796332] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 Dec 26 06:37:25 magalas kernel: [ 23.796364] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff800012608000 base addr 0x000006c0c00000 Dec 26 06:37:25 magalas kernel: [ 23.796366] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800021800000 base addr 0x000006c0000000 size 0x800000 Dec 26 06:37:25 magalas kernel: [ 23.901710] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' Dec 26 06:37:25 magalas kernel: [ 23.901711] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' Dec 26 06:37:25 magalas kernel: [ 23.901712] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' Dec 26 06:37:25 magalas kernel: [ 23.901713] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' Dec 26 06:37:25 magalas kernel: [ 23.901714] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' Dec 26 06:37:25 magalas kernel: [ 23.901716] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m Dec 26 06:37:25 magalas kernel: [ 23.902272] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 Dec 26 06:37:25 magalas kernel: [ 23.902849] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 Dec 26 06:37:25 magalas kernel: [ 23.903920] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. Dec 26 06:37:25 magalas kernel: [ 23.903923] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a Dec 26 06:37:25 magalas kernel: [ 24.050834] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 Dec 26 06:37:25 magalas kernel: [ 24.051735] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) Dec 26 06:37:25 magalas kernel: [ 24.051843] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init Dec 26 06:37:25 magalas kernel: [ 30.049265] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize

Ry

pipcet commented 2 years ago

Yes, there was a typo. Sorry about that. (You can fix /etc/modprobe.d/brcmfmac.conf manually (it should not have any quotes, single or double) (note that the change will be overwritten after a reboot). The output looks effectively identical to the first attempt here, but not to the second attempt which succeeds here but fails for you (you're seeing the "FW failed to initialize" line three times after a reboot, right?)

pipcet commented 2 years ago

...actually, you should see it ten times. Do you have any unusual USB devices connected? Can you try booting with themall USB devices disconnected?

Johnnie390 commented 2 years ago

Pip,

with brcmfmac.conf corrected and an insmod (modprobe) here is the output -

[Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_register Enter [Sun Dec 26 13:54:49 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff8000125f0000 base addr 0x000006c0c00000 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800025800000 base addr 0x000006c0000000 size 0x800000 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' [Sun Dec 26 13:54:49 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sun Dec 26 13:54:49 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init [Sun Dec 26 13:54:56 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize [Sun Dec 26 13:54:56 2021] brcmfmac: brcmf_pcie_remove Enter

Johnnie390 commented 2 years ago

Pip,

with brcmfmac.conf corrected and an insmod (modprobe) here is the output -

[Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_register Enter [Sun Dec 26 13:54:49 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff8000125f0000 base addr 0x000006c0c00000 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800025800000 base addr 0x000006c0000000 size 0x800000 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' [Sun Dec 26 13:54:49 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sun Dec 26 13:54:49 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) [Sun Dec 26 13:54:49 2021] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init [Sun Dec 26 13:54:56 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize [Sun Dec 26 13:54:56 2021] brcmfmac: brcmf_pcie_remove Enter

Johnnie390 commented 2 years ago

Pip,

the only "thing" I have connected at boot is a USB hub with keyboard and mouse connected. The USB hub is connected to the Thunderbolt 3 (USB-C) port nearest to the HDMI port if this makes a difference.

Ry

pipcet commented 2 years ago

And you're seeing that ten times in dmesg after boot, or does it break out of the loop prematurely? Sorry I have so many questions, I'm a bit puzzled what the difference between our systems could be :-)

It seems that for whatever reason:

  1. on the first attempt to load the driver, the phys don't come up properly
  2. the driver then attempts to reset the device and reload
  3. your device doesn't reset properly; mine does
Johnnie390 commented 2 years ago

Pip,

where is your Pearl startup log located? I am indeed seeing ...phy... not attached messages during startup, but they fly by to fast to make a note of them. Or can I interrupt or pause the Pearl startup sequence to trap the message(s))??

Ry

pipcet commented 2 years ago

dmesg once the system is up works here.

Johnnie390 commented 2 years ago

Here also, I am also seeing phy messages in syslog and messages but all relating to TG3. I am talking about earlier in the bootstrap process that the fly-by phy messages are appearing and disappearing.

Johnnie390 commented 2 years ago

This message appeared in the final stage boot - Dec 26 06:37:25 magalas kernel: [ 20.638681] ieee80211 phy0: brcmf_attach_postirq: dongle is not responding: err=-5

But I am talking about "phy" brcm... messages much earlier in the Pearl bootstrap process.

pipcet commented 2 years ago

You're right, dmesg only goes back to the beginning of the third/final stage. However, the earlier stages shouldn't interact with the brcm hardware at all, so I'm a bit confused. In fact, it's not visible until the SMC power gate is enabled, at least over here.

I've gone over the brcmfmac firmware initialization code and there's one fairly obvious bug that might result in all kinds of misbehavior: the firmware buffer is appended to even if its length has stayed unmodified, overwriting random memory. That's certainly consistent with my "try a few times and usually it works" observation...

Johnnie390 commented 2 years ago

Let me try a boot again and I will to trap these message or take a (very quick reaction) photo of them. I have a 2020 M1 Mini with 16GB RAM and a 500GB NVME SSD - Model A2348 FWIW.

Johnnie390 commented 2 years ago

See if you can

https://user-images.githubusercontent.com/22815859/147411054-a9f50348-d742-462c-971c-6b7aa18d2b91.MOV

https://user-images.githubusercontent.com/22815859/147411049-f2d7d9f3-9615-4306-9b05-5b8a5fdb5bba.MOV

make anything of these (very quick) clips -

https://user-images.githubusercontent.com/22815859/147411057-bd770b33-27cc-45f4-b95f-4361736843ae.MOV

pipcet commented 2 years ago

Hmm. The message at 20.124500 really looks like the brcmfmac module initialized fine and should work without further interaction...are you sure it doesn't (it's using the Honshu firmware rather than the Atlantis B one, but that seems to work fine here)?

So my suggestion would be to run "ifconfig -a" as root right after booting, to see whether a wireless interface shows up (you might have to install net-tools first since "ifconfig" has been replaced by something I don't understand :-) )

Johnnie390 commented 2 years ago

Indeed. Have you copied brcmfmac.conf from /persist to /etc/modprobe.d/? I corrected the syntax error therein and am now receiving the following when I issue a modprobe -vv brcmfmac

[Sun Dec 26 15:36:03 2021] brcmfmac: brcmf_pcie_register Enter [Sun Dec 26 15:36:03 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 15:36:03 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 [Sun Dec 26 15:36:03 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff8000125e8000 base addr 0x000006c0c00000 [Sun Dec 26 15:36:03 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800021800000 base addr 0x000006c0000000 size 0x800000 [Sun Dec 26 15:36:03 2021] brcmfmac: brcmf_chip_get_raminfo: RAM size is undetermined [Sun Dec 26 15:36:03 2021] brcmfmac: brcmf_pcie_probe: failed 14e4:4425 [Sun Dec 26 15:36:03 2021] brcmfmac: probe of 0000:01:00.0 failed with error -12

Notice no "failed to initialize NVRAM..." this time. Odd.

brcmfmac.conf -

options brcmfmac nvram_mac_addr=1666CDC80FE4 debug=524288

Johnnie390 commented 2 years ago

...and yes there is a wlan0 present immediately after a reboot. However this disappears after the first rmmod...

Johnnie390 commented 2 years ago

I have commented out the options parameter in both brcmfmac.conf files mentioned above and ran rmmod and modprobe -vv brcmfmac again - the same result -

[Sun Dec 26 15:51:23 2021] brcmfmac: brcmf_pcie_exit Enter [Sun Dec 26 15:51:35 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 15:51:35 2021] brcmfmac: brcmf_chip_get_raminfo: RAM size is undetermined [Sun Dec 26 15:51:35 2021] brcmfmac: brcmf_pcie_probe: failed 14e4:4425 [Sun Dec 26 15:51:35 2021] brcmfmac: probe of 0000:01:00.0 failed with error -12

Ry

pipcet commented 2 years ago

Does wlan0 work if you never do the first rmmod and just leave things otherwise?

Johnnie390 commented 2 years ago

TBH I cannot remember. Have just rebooted, no wlan0... After the usual rmmod and modprobe, things are back to "normal" -

[Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_register Enter [Sun Dec 26 16:05:17 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff800014ce8000 base addr 0x000006c0c00000 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800021800000 base addr 0x000006c0000000 size 0x800000 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' [Sun Dec 26 16:05:17 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sun Dec 26 16:05:17 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) [Sun Dec 26 16:05:17 2021] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init [Sun Dec 26 16:05:23 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize [Sun Dec 26 16:05:23 2021] brcmfmac: brcmf_pcie_remove Enter

pipcet commented 2 years ago

Note that Debian will rename wlan0 to wlp*, so it might still work...

Johnnie390 commented 2 years ago

Before I retire for the evening I will try a complete power-off and try again.

Johnnie390 commented 2 years ago

After a complete power-off and restart, things are still the same. At this stage, no rmmod or modprobe commands have been attempted.

[Sun Dec 26 16:30:00 2021] brcmfmac: brcmf_pcie_remove Enter [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_exit Enter [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_register Enter [Sun Dec 26 16:30:03 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff800012608000 base addr 0x000006c0c00000 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800021800000 base addr 0x000006c0000000 size 0x800000 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1' [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP' [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11' [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element '' [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m' [Sun Dec 26 16:30:03 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m [Sun Dec 26 16:30:03 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM. [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e260 0x1da0 [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf8980767) [Sun Dec 26 16:30:03 2021] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init [Sun Dec 26 16:30:09 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize [Sun Dec 26 16:30:09 2021] brcmfmac: brcmf_pcie_remove Enter

Just sent you a link to the Pearl-startup film I made.

pipcet commented 2 years ago

Hmm, can't see the film. Looking forward to it once it's there :-) Thanks for all the testing!

Johnnie390 commented 2 years ago

Check your gmail.

pipcet commented 2 years ago

The folder you shared appears empty from here...

Johnnie390 commented 2 years ago

Try again perhaps.

Johnnie390 commented 2 years ago

Manage to find the film?

Try again perhaps.

pipcet commented 2 years ago

Thank you, I found it. It now looks to me like the root of the troubles might be my rather impatient 3 second timeout, and I'm currently having a "release" built with an 8 second timeout between driver loads which might be better. It also includes some debug code to dump the NVRAM it is about to load, and a minor fix to avoid the buffer overrun that must have occurred but might have been harmless. I'll give it a spin once it's done.

Johnnie390 commented 2 years ago

Pip, any new developments/releases here?

pipcet commented 2 years ago

GitHub is having trouble, it seems.

pipcet commented 2 years ago

...or was having trouble, this run actually looks good so far :-)

Johnnie390 commented 2 years ago

Please let me know when I should descend to the boiler room. :)

pipcet commented 2 years ago

Okay, that took a while longer that usual, but the build has finally finished, and it boots on my mini, so I'd be very interested to know:

  1. if it gets you a working wlan0/wlp* interface if you boot without further rmmoding/modprobing
  2. if it doesn't, how many "NVRAM" blocks you see during boot. There should be ten, if it doesn't work, and the process should take about a minute and a half.

Note that the tg3 problems are still present, and there's copious debug output so this "release" isn't all that usable with standard logrotate settings.

Thanks, as always, for all the testing efforts!

Pip

Johnnie390 commented 2 years ago

Must put on my overalls on first. Will report back.