8000 M1 Mini - Boot persistence · Issue #31 · pipcet/pearl · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

M1 Mini - Boot persistence #31

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
Johnnie390 opened this issue Dec 19, 2021 · 125 comments
Open

M1 Mini - Boot persistence #31

Johnnie390 opened this issue Dec 19, 2021 · 125 comments

Comments

@Johnnie390
Copy link

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.

@pipcet
Copy link
Owner
pipcet commented Dec 19, 2021

Well, first, the obligatory warning: using the NVMe disk might put your device into a state that requires DFU mode to restore. (That said, this only happened to me once, when I deliberately modified the recovery partition to see what would happen.)

The most important part is not to touch the Apple partitions. That means using the Apple Disk Utility to create one (or several) MS-DOS partitions that Linux can then use (it doesn't care much about the partition type in the partition table). The second most important part is that fatfs currently is not supported: it syncs to disk in a way the Linux NVMe driver doesn't understand yet, so changes might not be written after an fsync.

So, from memory:

  1. boot into Recovery Mode
  2. launch the Disk Utility and repartition so you have a large MS-DOS partition, but keep the existing Apple partitions
  3. decide whether you want to use LVM or not
  4. (if using LVM) configure pearl to boot from /dev/mapper/[volume group name]-[logical volume name], even though the volume group doesn't exist yet. Just choose any useful pair of names.
  5. (if not using LVM) configure pearl to boot from /dev/mapper/nvme0n1p3 /dev/nvme0n1p3, unless you have additional partitions, in which case you might have to go back and fix the partition number later
  6. launch the Debian installer
  7. when reaching that point, choose "manual" partitioning. Do not choose "guided-use entire disk" as the Apple parts of the disk need to be present for pearl to work.
  8. (if using LVM) use the existing MS-DOS partition as an LVM physical volume, set up an LVM volume group (name as above), a logical volume in it (name as above), and set it up as an ext4 root file system
  9. (if not using LVM) use the existing MS-DOS partition as an ext4 root file system
  10. proceed to install
  11. reboot

If all goes well, you will boot to your new Debian system automatically. If things do not go well, do the following:

  1. start pearl
  2. open a shell prompt (in the lower right window)
  3. enter
echo shell > /persist/finalchoices
final
  1. get a shell prompt (hopefully) to figure out what's gone wrong, mount the root file system to /mnt, and execute exec switch_root /mnt /sbin/init
  2. note that you will have to do this every time until you fix your pearl nvram variable, in Recovery Mode, by executing nvram pearl="root /dev/nvme0n1p17;delay 180;no4k" or similar. Also, pearl does additional magic to install WiFi firmware and kernel modules, so it's better not to use the finalchoices=shell approach unless you have to for some reason, or to copy the relevant magic from bin/init-final

Btrfs does work but requires extra setup (debian defaults, when creating a btrfs root file system, to putting its stuff in a subvolume, and pearl attempts to mount the main volume, so /sbin/init doesn't exist). Ext4 should work. Other file systems most likely will not work, and become corrupted after you attempt to mount them because some data will be written back to the file system and some won't. In particular, this means FAT.

(Edited to fix incorrect /dev/ path)

@Johnnie390
Copy link
Author

Hello Pip,

be MS-DOS partition, I presume you mean an EX-FAT partition?

Regards,

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 20, 2021

I use the option called "MS-DOS (FAT32)" in Disk Utility, but ExFAT ought to work as well if you don't see the option for some reason. The partition is then reformatted as a different file system which macOS should be unable to recognize...

@pipcet
Copy link
Owner
pipcet commented Dec 20, 2021

Oh, and of course, do feel free to leave questions or comments. As I said, it was from memory, though I'm currently going through an install with the new kernel on the update branch and it appears to be working so far.

One gotcha is that it's very advisable to suggest a desktop environment; without it, you won't get network-manager, and it'll be harder to connect the machine to a network again.

Just as a reminder, it is of course possible to install different distributions, as long as those distributions accept being switched to using a foreign kernel (and, alas, as long as they're okay with a 16 KB page size). Technically, of course, we're not running Debian, but the Debian userspace with our own kernel and modules.

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 22, 2021

Hello Pip,
did as you suggested until I got to the Debian (11) Installer, manually partition disk (NVME) etc. no problems. At the end of the Debian install, I get this message (see attached photo).

Regards,
IMG_0149

I have tried a straight reboot and a power recycle, in both cases, your pearl script starts again.
Am I missing a step here?

Regards

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 22, 2021

Are you saying you are selecting "final" in the boot menu, and it boots to the installer again, after the installation? Can you open a shell and cat /persist/root in it to see it's correct?

(Unfortunately, there's a bug that I only fixed today which means you have to hit enter once on the pearl screen rather than just waiting for it to go away. Sorry about that).

@pipcet
Copy link
Owner
pipcet commented Dec 22, 2021

The message is okay, by the way. Pearl is the boot loader, the Debian installer just doesn't know it exists :-)

@Johnnie390
Copy link
Author

"Are you saying you are selecting "final" in the boot menu, and it boots to the installer again, after the installation? Can you open a shell and cat /persist/root in it to see it's correct? - I select Install (Debian Installer) from your menu.

No, after the "successful" Debian install, after a power off/on, your perl script (no4k, delay, root /dev/... etc.) starts automatically.

@Johnnie390
Copy link
Author

cat /persist/root /dev/mapper/nvme0n1p3. This looks correct.

@pipcet
Copy link
Owner
pipcet commented Dec 22, 2021

I'm not sure I understand how that can happen. What should happen is that after the power on, you see the pearl 4-screen split-screen again, select "final", and it should boot to Debian. Are you saying you're seeing Recovery Mode instead?

Maybe a screenshot could help me understand what you're seeing.

@Johnnie390
Copy link
Author

Pip,

"What should happen is that after the power on, you see the pearl 4-screen split-screen again, select "final", and it should boot to Debian." No, it would seem the Perl/Debian installer is starting again when I select "final". Please see screen shot.
IMG_0150

Regards,

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 22, 2021

Oh, you have /dev/mapper/nvme0n1p3, not /dev/nvme0n1p3. Can you try fixing that for one boot by opening a shell (from the pearl menu) and running

root /dev/nvme0n1p3
final

If you're happy with the results, you can go into the Recovery Mode terminal and run

nvram pearl='no4k;root /dev/nvme0n1p3;delay 180'

(or whatever) to see whether it works automatically, though you'll still have to select "final" manually until tomorrow's release.

@pipcet
Copy link
Owner
pipcet commented Dec 22, 2021

Sorry about that mistake, by the way. Entirely my fault, should be fixed in the instructions now.

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 23, 2021

Hello Pip,

you boot persistence Debian Installer works! My compliments on the brain cells expended to get this to work. Chapeau!
A few observations..
When I select "final" from your Pearl menu, the Debian code I installed appears to kick-off, but halts.
I can however open another TTY and type "startx" which brings me to the LXQT which I chose yesterday from the Debian Installer (tasksel).
In directory /persist, I have two tar files - i) brcmfmac.tar and ii) wifi.tar. should I do anything with these files?
When I started the Debian Installer yesterday, it installed a 5.10.0-10-arm64 kernel. When I boot using the Pearl script, I eventually land on the LXQt desktop, but using (your) kernel 5.16.0-rc5.
root@magalas:/Transit# ll /lib/modules
total 16
4 drwxr-xr-x 4 1001 sddm 4096 Dec 22 02:50 .
4 drwxr-xr-x 77 1001 sddm 4096 Dec 23 11:42 ..
4 drwxr-xr-x 3 root root 4096 Dec 23 08:34 5.10.0-10-arm64
4 drwxr-xr-x 3 1001 sddm 4096 Dec 23 12:54 5.16.0-rc5
root@magalas:/Transit# uname -a
Linux magalas 5.16.0-rc5 #1 SMP Wed Dec 22 00:45:55 UTC 2021 aarch64 GNU/Linux
Maybe there are too many abstraction layers at play here?

I also observe the (ethernet) internet speed is not what I expect, somwehat slow.
Can I at this stage, enable 4K dynamically or do I have to go back to the Pearl script?
My LXQT monitor settings is still reporting 1920x1080 @ 0Hz... XRANDR also.

Regards,

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 23, 2021

Hello Ry,
that's excellent news!

When I select "final" from your Pearl menu, the Debian code I installed appears to kick-off, but halts.

Hmm. What does cat /proc/cmdline say? It's possible a debug setting was left in there.

In directory /persist, I have two tar files - i) brcmfmac.tar and ii) wifi.tar. should I do anything with these files?

I think we're currently unpacking them automatically, so you can probably delete them; in any case, they're both necessary for WiFi but nothing else.

When I started the Debian Installer yesterday, it installed a 5.10.0-10-arm64 kernel. When I boot using the Pearl script, I eventually land on the LXQt desktop, but using (your) kernel 5.16.0-rc5.

Yes. The way it currently is is that Debian installs a 5.10 kernel but it's never used. Uninstalling the Debian kernel package causes dependency woes, so I just left both installed for now.

It's true that /lib/modules contains subdirectories for both kernels; right now, the way that happens is a bit of a hack, because I've been stuck in a system that couldn't get the network modules to get the other modules once too often :-)

Anyway, apart from the wasted disk space, this shouldn't cause major issues.

Maybe there are too many abstraction layers at play here?

Almost certainly :-)

I also observe the (ethernet) internet speed is not what I expect, somwehat slow.

Is this with or without the EEE firmware? dmesg should have some messages from the tigon/tg driver explaining whether the firmware was found. (I have Ethernet set up to the mini but don't use it much, usually going for WiFi only; I did notice some connection speed issues but thought they had since been fixed...)

Can I at this stage, enable 4K dynamically or do I have to go back to the Pearl script?

I'm afraid at this point you'll have to go back to Recovery Mode and modify the nvram variable, either directly or by running the Pearl perl script again (note, though, that there was just a new "release" and I haven't been able to test it yet).

Thanks, again, for all the testing,
Pip

@Johnnie390
Copy link
Author

Pip,

EEE firmware??? Here is an excerpt from dmesg -

root@magalas:~# dmesg |grep -i tg
[ 6.314179] tg3 0000:03:00.0: deferred probe timeout, ignoring dependency
[ 6.314990] tg3 0000:03:00.0: of_irq_parse_pci: failed with rc=-22
[ 6.315795] tg3 0000:03:00.0: enabling device (0000 -> 0002)
[ 6.332721] tg3 0000:03:00.0 eth0: Tigon3 [partno(BCM57762) rev 57766000] (PCI Express) MAC address 00:10:18:00:00:00
[ 6.333545] tg3 0000:03:00.0 eth0: attached PHY is 57765 (10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
[ 6.334366] tg3 0000:03:00.0 eth0: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[0] TSOcap[1]
[ 6.335187] tg3 0000:03:00.0 eth0: dma_rwctrl[00000001] dma_mask[64-bit]
[ 16.781417] tg3 0000:03:00.0: Adding to iommu group 3
[ 16.782088] tg3 0000:03:00.0: of_irq_parse_pci: failed with rc=-22
[ 16.794344] tg3 0000:03:00.0 eth0: Tigon3 [partno(BCM57762) rev 57766000] (PCI Express) MAC address 00:10:18:00:00:00
[ 16.794826] tg3 0000:03:00.0 eth0: attached PHY is 57765 (10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
[ 16.795305] tg3 0000:03:00.0 eth0: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[0] TSOcap[1]
[ 16.795780] tg3 0000:03:00.0 eth0: dma_rwctrl[00000001] dma_mask[64-bit]
[ 40.116549] tg3 0000:03:00.0 eth0: Link is up at 100 Mbps, full duplex
[ 40.118160] tg3 0000:03:00.0 eth0: Flow control is off for TX and off for RX
[ 40.119756] tg3 0000:03:00.0 eth0: EEE is disabled

Regards,

Ry

@Johnnie390
Copy link
Author

The penny drops -
root@magalas:~# ethtool --show-eee eth0
EEE settings for eth0:
EEE status: enabled - inactive
Tx LPI: 2047 (us)
Supported EEE link modes: 100baseT/Full
1000baseT/Full
Advertised EEE link modes: 100baseT/Full
1000baseT/Full
Link partner advertised EEE link modes: Not reported

@Johnnie390
Copy link
Author

Pip,

just tried your latest release, this time omitting the "no4k" NVRAM parameter.
Kernel panic, please see screenshot -

IMG_0155

@pipcet
Copy link
Owner
pipcet commented Dec 23, 2021

Yes, I messed up that one :-( It's salvageable (I'm running it), but that's probably not necessary or useful. The release has been deleted, so if you reinstall it should go back to the previous, kinda-working one.

@Johnnie390
Copy link
Author

Have done so. Unfortunately, I will have to start the no4k dance with Pearl again.

@Johnnie390
Copy link
Author

Pip,

also seeing this -

@magalas:~# dmesg |grep brcmf
[ 12.911927] brcmfmac 0000:01:00.0: Adding to iommu group 5
[ 12.912513] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[ 12.912906] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
[ 13.022162] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[ 13.022587] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[ 13.023030] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 15.901687] ieee80211 phy0: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 15.902159] ieee80211 phy0: brcmf_c_preinit_dcmds: Retrieving cur_etheraddr failed, -5
[ 15.902630] ieee80211 phy0: brcmf_bus_started: failed: -5
[ 15.903108] ieee80211 phy0: brcmf_attach_postirq: dongle is not responding: err=-5
[ 19.059089] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[ 19.166177] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[ 19.167456] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[ 19.168805] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 25.317688] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize
[ 28.222945] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[ 28.330175] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[ 28.331755] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[ 28.333370] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 28.983964] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 29.002651] 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
[ 35.165689] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 37.181685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 37.182375] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 39.197688] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 39.198421] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 41.213686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command

[ 83.549685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 85.565685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 87.581689] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 87.582689] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 89.597684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 89.598666] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 91.613685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 91.614661] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 93.629688] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 93.630673] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 95.645686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 97.661687] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 99.677684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 99.678635] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 101.693684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 101.694641] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 103.709686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 103.710640] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 105.725683] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 105.726611] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 107.741686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 107.742612] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 109.757681] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 109.758593] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 111.773683] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 111.774621] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 113.789686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 113.790626] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 115.805681] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 115.806594] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 117.821682] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 117.822589] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 119.837687] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 119.838592] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 121.853687] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 121.854575] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 123.869694] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 125.885684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 127.902906] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 127.903796] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 129.923090] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 129.923993] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 131.942759] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 131.943675] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 133.961991] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 133.962946] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 135.980809] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 137.999294] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 140.017473] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 140.018384] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 142.035386] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 142.036293] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
.
.
.
[ 158.173194] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 158.174666] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 158.175599] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-12)
[ 158.176538] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 158.177475] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-12)
[ 158.178429] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 158.179359] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring

Any ideas?

1 similar comment
@Johnnie390
Copy link
Author

Pip,

also seeing this -

@magalas:~# dmesg |grep brcmf
[ 12.911927] brcmfmac 0000:01:00.0: Adding to iommu group 5
[ 12.912513] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[ 12.912906] brcmfmac 0000:01:00.0: enabling device (0000 -> 0002)
[ 13.022162] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[ 13.022587] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[ 13.023030] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 15.901687] ieee80211 phy0: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 15.902159] ieee80211 phy0: brcmf_c_preinit_dcmds: Retrieving cur_etheraddr failed, -5
[ 15.902630] ieee80211 phy0: brcmf_bus_started: failed: -5
[ 15.903108] ieee80211 phy0: brcmf_attach_postirq: dongle is not responding: err=-5
[ 19.059089] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[ 19.166177] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[ 19.167456] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[ 19.168805] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 25.317688] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize
[ 28.222945] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[ 28.330175] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[ 28.331755] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[ 28.333370] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 28.983964] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[ 29.002651] 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
[ 35.165689] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 37.181685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 37.182375] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 39.197688] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 39.198421] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 41.213686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command

[ 83.549685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 85.565685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 87.581689] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 87.582689] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 89.597684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 89.598666] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 91.613685] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 91.614661] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 93.629688] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 93.630673] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 95.645686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 97.661687] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 99.677684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 99.678635] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 101.693684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 101.694641] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 103.709686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 103.710640] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 105.725683] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 105.726611] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 107.741686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 107.742612] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 109.757681] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 109.758593] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 111.773683] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 111.774621] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 113.789686] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 113.790626] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 115.805681] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 115.806594] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 117.821682] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 117.822589] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 119.837687] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 119.838592] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 121.853687] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 121.854575] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 123.869694] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 125.885684] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 127.902906] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Ti 8000 meout on response for query command
[ 127.903796] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 129.923090] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 129.923993] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[ 131.942759] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 131.943675] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[ 133.961991] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 133.962946] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 135.980809] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 137.999294] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 140.017473] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 140.018384] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-5)
[ 142.035386] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[ 142.036293] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
.
.
.
[ 158.173194] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[ 158.174666] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 158.175599] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-12)
[ 158.176538] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 158.177475] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-12)
[ 158.178429] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 158.179359] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring

Any ideas?

@Johnnie390
Copy link
Author

Github playing tricks again. I had to close and reopen this issue again.
Now on 4K FWIW.

@pipcet
Copy link
Owner
pipcet commented Dec 23, 2021

Any ideas?

Problem in the wifi driver. Are you using it? Maybe it doesn't like being loaded but unused, and you could just rmmod it?

@Johnnie390
Copy link
Author
Johnnie390 comm 6D40 ented Dec 23, 2021

Pip,

trying to. The wifi part is proving to be a stubborn beast -
modprobe -r brcmfmac; modprobe brcmfmac debug=2097150
[Thu Dec 23 16:19:04 2021] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[Thu Dec 23 16:19:04 2021] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[Thu Dec 23 16:19:04 2021] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid
[Thu Dec 23 16:19:04 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[Thu Dec 23 16:19:04 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[Thu Dec 23 16:19:04 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[Thu Dec 23 16:19:04 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[Thu Dec 23 16:19:10 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize

Regards,

Ry

@Johnnie390
Copy link
Author

"cfg80211: loaded regulatory.db is malformed or signature is missing/invalid" is fixed. The ...FW failed to initialise stuff persists.

@pipcet
Copy link
Owner
pipcet commented Dec 27, 2021

GitHub is having trouble, it seems.

@pipcet
Copy link
Owner
pipcet commented Dec 27, 2021

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

@Johnnie390
Copy link
Author

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

@pipcet
Copy link
Owner
pipcet commented Dec 27, 2021

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
Copy link
Author

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

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 27, 2021

Pip,

still the same unfortunately.
root@magalas:~# ifconfig -a
eth0: flags=-28605<UP,BROADCAST,RUNNING,MULTICAST,DYNAMIC> mtu 1500
inet 192.168.0.98 netmask 255.255.255.0 broadcast 192.168.0.255
ether 00:10:18:00:00:00 txqueuelen 1000 (Ethernet)
RX packets 12485 bytes 17518398 (16.7 MiB)
RX errors 0 dropped 2 overruns 0 frame 0
TX packets 6723 bytes 574390 (560.9 KiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536
inet 127.0.0.1 netmask 255.0.0.0
loop txqueuelen 1000 (Local Loopback)
RX packets 21 bytes 1603 (1.5 KiB)
RX errors 0 dropped 0 overruns 0 frame 0
TX packets 21 bytes 1603 (1.5 KiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

A lot of NVRAM diagnostics/dumping at startup.
.
.
.
[Mon Dec 27 15:26:54 2021] NVRAM:00001ce0: 00313d6b 6d797361 746e695f 5f667265 k=1.asym_interf_
[Mon Dec 27 15:26:54 2021] NVRAM:00001cf0: 5f74696d 313d6e65 79736100 6e695f6d mit_en=1.asym_in
[Mon Dec 27 15:26:54 2021] NVRAM:00001d00: 66726574 696f6e5f 645f6573 61746c65 terf_noise_delta
[Mon Dec 27 15:26:54 2021] NVRAM:00001d10: 7268745f 3d687365 73610035 695f6d79 _thresh=5.asym_i
[Mon Dec 27 15:26:54 2021] NVRAM:00001d20: 7265746e 6f6e5f66 5f657369 63736964 nterf_noise_disc
[Mon Dec 27 15:26:54 2021] NVRAM:00001d30: 5f647261 6772616d 325f6e69 00333d67 ard_margin_2g=3.
[Mon Dec 27 15:26:54 2021] NVRAM:00001d40: 6d797361 746e695f 5f667265 73696f6e asym_interf_nois
[Mon Dec 27 15:26:54 2021] NVRAM:00001d50: 69645f65 72616373 616d5f64 6e696772 e_discard_margin
[Mon Dec 27 15:26:54 2021] NVRAM:00001d60: 3d67355f 73610030 695f6d79 7265746e 5g=0.asym_inter
[Mon Dec 27 15:26:54 2021] NVRAM:00001d70: 6f6e5f66 5f657369 63736964 5f647261 f_noise_discard

[Mon Dec 27 15:26:54 2021] NVRAM:00001d80: 6772616d 355f6e69 61675f67 35346e69 margin_5g_gain45
[Mon Dec 27 15:26:54 2021] NVRAM:00001d90: 0000373d 00000000 00000000 f8980767 =7..........g...
.
.
.

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

Do you need any logs?

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 27, 2021

Bummer. Any idea what might have gone differently with the boot which gave you a wlan0 interface?

dmesg log for one load-unload cycle would be wonderful, yes.

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 28, 2021

Pip,

here is a short log immediately after issuing these commands -
rmmod brcmfmac brcmutil && sleep 2 && modprobe brcmfmac.

brcm.txt

@Johnnie390
Copy link
Author

Pip,

just rebooted. Did nothing special, just a routine restart.

Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 271 (0), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 272 (0), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 273 (0), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 280 (280), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 600 (599), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 600 (600), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 280 (280), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 601 (600), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 601 (601), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 280 (280), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 602 (601), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 602 (602), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 330 (0), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 280 (280), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 603 (602), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 603 (603), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 281 (280), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 281 (281), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 603 (603), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 331 (0), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 281 (281), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 604 (603), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 604 (604), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 282 (281), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 282 (282), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 604 (604), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 283 (282), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 283 (283), ring 4
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 604 (604), ring 3
[Tue Dec 28 13:34:12 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 274 (0), ring 3
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_quick_check_isr Enter
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_isr_thread Enter 1
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 283 (283), ring 4
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 605 (604), ring 3
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_ring_mb_write_rptr W r_ptr 605 (605), ring 3
[Tue Dec 28 13:34:17 2021] brcmfmac: brcmf_pcie_ring_mb_update_wptr R w_ptr 9 (9), ring 2
root@magalas:#
root@magalas:
# iwconfig
lo no wireless extensions.

wlan0 IEEE 802.11 ESSID:"Propodopolus"
Mode:Managed Frequency:2.437 GHz Access Point: B8:BE:F4:B5:7B:EE
Bit Rate=144.4 Mb/s Tx-Power=31 dBm
Retry short limit:7 RTS thr:off Fragment thr:off
Encryption key:off
Power Management:off
Link Quality=66/70 Signal level=-44 dBm
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:0 Missed beacon:0

enx560910d15459 no wireless extensions.

Wavemon

This is very frustrating and as far as I know, impossible to reproduce.
I will leave things as they are (no rmmods or modprobes) until you are online.

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 28, 2021

Well, at least we know the hardware's working now :-) It is frustrating that I'm not seeing any failures at all, but you're seeing them (it seems) randomly, and in most cases.

What I'm thinking is we need to reset the hardware more thoroughly in between attempts...

It would be interesting to know whether the driver reloads if you don't do another hardware reset, just rmmod/modprobe. I'll try to see what happens if I toggle the SMC power gate after unloading the driver, but I suspect it'll just crash the mini.

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 28, 2021

Pip,

the connection took it's leave a few minutes ago.
It is now running again with some nmcli intervention.
NMCLI-I

With "nmcli dev wifi connect Propodopolus password xxxxxx" I was able to reconnect.
There is no informational/error or diagnostic messages in the ring buffer or syslog.

@Johnnie390
Copy link
Author

Pip,

after a rmmod/modprobe the interface did not disappear, but has been very verbal in syslog -

Dec 28 14:05:45 magalas kernel: [ 2820.591359] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:47 magalas NetworkManager[44149]: [1640696747.3017] platform-linux: do-change-link[7]: failure changing link: failure 5 (Input/output error)
Dec 28 14:05:47 magalas kernel: [ 2822.607374] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:47 magalas kernel: [ 2822.607386] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
Dec 28 14:05:47 magalas kernel: [ 2822.607734] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 38 (59), ring 0
Dec 28 14:05:47 magalas kernel: [ 2822.607740] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:49 magalas kernel: [ 2824.623410] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:49 magalas kernel: [ 2824.623419] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:05:49 magalas kernel: [ 2824.623425] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 39 (59), ring 0
Dec 28 14:05:49 magalas kernel: [ 2824.623429] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:51 magalas kernel: [ 2826.639448] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:51 magalas kernel: [ 2826.639456] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:05:51 magalas kernel: [ 2826.639669] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 40 (59), ring 0
Dec 28 14:05:51 magalas kernel: [ 2826.639674] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:53 magalas NetworkManager[44149]: [1640696753.3496] platform-linux: do-change-link[7]: failure changing link: failure 5 (Input/output error)
Dec 28 14:05:53 magalas NetworkManager[44149]: [1640696753.3497] device (wlan0): set-hw-addr: failed to set MAC address to 6E:D8:9C:95:2E:73 (scanning) (NME_UNSPEC)
Dec 28 14:05:53 magalas kernel: [ 2828.655492] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:53 magalas kernel: [ 2828.655500] ieee80211 phy3: brcmf_netdev_set_mac_address: Setting cur_etheraddr failed, -5
Dec 28 14:05:53 magalas kernel: [ 2828.655730] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 41 (59), ring 0
Dec 28 14:05:53 magalas kernel: [ 2828.655735] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:55 magalas kernel: [ 2830.675520] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:55 magalas kernel: [ 2830.675533] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 42 (59), ring 0
Dec 28 14:05:55 magalas kernel: [ 2830.675539] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:57 magalas kernel: [ 2832.687562] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:57 magalas kernel: [ 2832.687574] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 43 (59), ring 0
Dec 28 14:05:57 magalas kernel: [ 2832.687579] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:05:57 magalas dhclient[3512]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 11
Dec 28 14:05:57 magalas dhclient[3512]: send_packet: No such device or address
Dec 28 14:05:57 magalas dhclient[3512]: dhclient.c:2446: Failed to send 300 byte long packet over wlan0 interface.
Dec 28 14:05:59 magalas kernel: [ 2834.703600] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:05:59 magalas kernel: [ 2834.703610] ieee80211 phy3: brcmf_dongle_scantime: Sc 10000 an assoc time error (-5)
Dec 28 14:05:59 magalas kernel: [ 2834.703616] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 44 (59), ring 0
Dec 28 14:05:59 magalas kernel: [ 2834.703620] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:01 magalas NetworkManager[44149]: [1640696761.4136] platform-linux: do-change-link[7]: failure changing link: failure 5 (Input/output error)
Dec 28 14:06:01 magalas kernel: [ 2836.719635] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:01 magalas kernel: [ 2836.719647] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
Dec 28 14:06:01 magalas kernel: [ 2836.720742] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 45 (59), ring 0
Dec 28 14:06:01 magalas kernel: [ 2836.720748] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:03 magalas kernel: [ 2838.735668] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:03 magalas kernel: [ 2838.735678] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:06:03 magalas kernel: [ 2838.735683] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 46 (59), ring 0
Dec 28 14:06:03 magalas kernel: [ 2838.735686] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:05 magalas kernel: [ 2840.751705] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:05 magalas kernel: [ 2840.751716] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:05 magalas kernel: [ 2840.751772] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 47 (59), ring 0
Dec 28 14:06:05 magalas kernel: [ 2840.751776] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:06 magalas NetworkManager[44149]: [1640696766.4198] device (wlan0): Couldn't initialize supplicant interface: Timeout was reached
Dec 28 14:06:07 magalas kernel: [ 2842.767741] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:07 magalas kernel: [ 2842.767751] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:07 magalas kernel: [ 2842.767771] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 48 (59), ring 0
Dec 28 14:06:07 magalas kernel: [ 2842.767775] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:08 magalas dhclient[3512]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 13
Dec 28 14:06:08 magalas dhclient[3512]: send_packet: No such device or address
Dec 28 14:06:08 magalas dhclient[3512]: dhclient.c:2446: Failed to send 300 byte long packet over wlan0 interface.
Dec 28 14:06:09 magalas kernel: [ 2844.783782] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:09 magalas kernel: [ 2844.783792] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:06:09 magalas kernel: [ 2844.783797] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 49 (59), ring 0
Dec 28 14:06:09 magalas kernel: [ 2844.783799] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:11 magalas kernel: [ 2846.799817] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:11 magalas kernel: [ 2846.799825] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:11 magalas kernel: [ 2846.800076] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 50 (59), ring 0
Dec 28 14:06:11 magalas kernel: [ 2846.800079] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:13 magalas kernel: [ 2848.815856] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:13 magalas kernel: [ 2848.815867] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:06:13 magalas kernel: [ 2848.815872] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 51 (59), ring 0
Dec 28 14:06:13 magalas kernel: [ 2848.815874] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:15 magalas kernel: [ 2850.831885] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:15 magalas kernel: [ 2850.831896] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:15 magalas kernel: [ 2850.831967] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 52 (59), ring 0
Dec 28 14:06:15 magalas kernel: [ 2850.831970] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:16 magalas NetworkManager[44149]: [1640696776.7563] device (wlan0): re-acquiring supplicant interface (#1).
Dec 28 14:06:17 magalas kernel: [ 2852.847927] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:17 magalas kernel: [ 2852.847937] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:06:17 magalas kernel: [ 2852.847942] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 53 (59), ring 0
Dec 28 14:06:17 magalas kernel: [ 2852.847944] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:19 magalas kernel: [ 2854.863958] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:19 magalas kernel: [ 2854.863968] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:19 magalas kernel: [ 2854.864588] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 54 (59), ring 0
Dec 28 14:06:19 magalas kernel: [ 2854.864591] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:21 magalas dhclient[3512]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 12
Dec 28 14:06:21 magalas dhclient[3512]: send_packet: No such device or address
Dec 28 14:06:21 magalas dhclient[3512]: dhclient.c:2446: Failed to send 300 byte long packet over wlan0 interface.
Dec 28 14:06:21 magalas kernel: [ 2856.879995] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:21 magalas kernel: [ 2856.880005] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:06:21 magalas kernel: [ 2856.880011] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 55 (59), ring 0
Dec 28 14:06:21 magalas kernel: [ 2856.880014] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:21 magalas NetworkManager[44149]: [1640696781.7616] device (wlan0): Couldn't initialize supplicant interface: Timeout was reached
Dec 28 14:06:23 magalas kernel: [ 2858.896038] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:23 magalas kernel: [ 2858.896048] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:23 magalas kernel: [ 2858.896115] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 56 (59), ring 0
Dec 28 14:06:23 magalas kernel: [ 2858.896118] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:25 magalas kernel: [ 2860.912069] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:25 magalas kernel: [ 2860.912080] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 57 (59), ring 0
Dec 28 14:06:25 magalas kernel: [ 2860.912083] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:27 magalas kernel: [ 2862.928107] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:27 magalas kernel: [ 2862.928119] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 58 (59), ring 0
Dec 28 14:06:27 magalas kernel: [ 2862.928122] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:29 magalas kernel: [ 2864.944144] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:29 magalas kernel: [ 2864.944154] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-5)
Dec 28 14:06:29 magalas kernel: [ 2864.944158] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (58), ring 0
Dec 28 14:06:29 magalas kernel: [ 2864.944161] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 59 (29), ring 0
Dec 28 14:06:29 magalas kernel: [ 2864.944162] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:31 magalas wpa_supplicant[2374]: Could not set interface wlan0 flags (UP): Input/output error
Dec 28 14:06:31 magalas wpa_supplicant[2374]: nl80211: Could not set interface 'wlan0' UP
Dec 28 14:06:31 magalas wpa_supplicant[2374]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Dec 28 14:06:31 magalas kernel: [ 2866.960191] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:31 magalas kernel: [ 2866.960207] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
Dec 28 14:06:31 magalas kernel: [ 2866.960292] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 60 (29), ring 0
Dec 28 14:06:31 magalas kernel: [ 2866.960301] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:31 magalas NetworkManager[44149]: [1640696791.7558] device (wlan0): re-acquiring supplicant interface (#2).
Dec 28 14:06:33 magalas dhclient[3512]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 1
Dec 28 14:06:33 magalas dhclient[3512]: send_packet: No such device or address
Dec 28 14:06:33 magalas dhclient[3512]: dhclient.c:2446: Failed to send 300 byte long packet over wlan0 interface.
Dec 28 14:06:33 magalas kernel: [ 2868.976215] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:33 magalas kernel: [ 2868.976225] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:33 magalas kernel: [ 2868.976321] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 61 (29), ring 0
Dec 28 14:06:33 magalas kernel: [ 2868.976330] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:34 magalas dhclient[3512]: No DHCPOFFERS received.
Dec 28 14:06:34 magalas dhclient[3512]: No working leases in persistent database - sleeping.
Dec 28 14:06:35 magalas kernel: [ 2870.992263] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:35 magalas kernel: [ 2870.992275] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-5)
Dec 28 14:06:35 magalas kernel: [ 2870.992281] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 62 (29), ring 0
Dec 28 14:06:35 magalas kernel: [ 2870.992286] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:36 magalas NetworkManager[44149]: [1640696796.7611] device (wlan0): Couldn't initialize supplicant interface: Timeout was reached
Dec 28 14:06:37 magalas kernel: [ 2873.008303] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:37 magalas kernel: [ 2873.008313] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-5)
Dec 28 14:06:37 magalas kernel: [ 2873.009185] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 63 (29), ring 0
Dec 28 14:06:37 magalas kernel: [ 2873.009190] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:39 magalas kernel: [ 2875.024334] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:39 magalas kernel: [ 2875.024343] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 0 (29), ring 0
Dec 28 14:06:39 magalas kernel: [ 2875.024347] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:41 magalas kernel: [ 2877.040370] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:41 magalas kernel: [ 2877.040380] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 1 (29), ring 0
Dec 28 14:06:41 magalas kernel: [ 2877.040383] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
Dec 28 14:06:43 magalas kernel: [ 2879.056405] ieee80211 phy3: brcmf_msgbuf_query_dcmd: Timeout on response for query command
Dec 28 14:06:43 magalas kernel: [ 2879.056412] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-5)
Dec 28 14:06:43 magalas kernel: [ 2879.056417] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 2 (29), ring 0
Dec 28 14:06:43 magalas kernel: [ 2879.056420] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !

@Johnnie390
Copy link
Author

Device is being stubborn in being brought online again -

2933.494028] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494030] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494032] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494033] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494034] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494035] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494037] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-12)
[ 2933.494038] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494039] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494040] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
[ 2933.494071] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494075] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494077] ieee80211 phy3: brcmf_cfg80211_get_channel: chanspec failed (-12)
[ 2933.494080] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494083] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494086] ieee80211 phy3: brcmf_cfg80211_get_tx_power: error (-12)
[ 2933.494446] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494449] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494451] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494452] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494454] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494455] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494456] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-12)
[ 2933.494458] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 2933.494459] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 2933.494460] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
[ 3062.539519] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.539527] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.539532] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.539534] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.539535] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.539537] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.539538] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-12)
[ 3062.539540] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.539542] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.539543] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
[ 3062.544095] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.544103] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.544108] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.544109] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.544111] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.544112] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.544114] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-12)
[ 3062.544116] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.544117] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.544119] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211
[ 3062.574980] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.574988] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.574993] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.574994] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.574996] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.574998] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.574999] ieee80211 phy3: brcmf_dongle_scantime: Scan assoc time error (-12)
[ 3062.575001] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 29 (28), ring 0
[ 3062.575003] ieee80211 phy3: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[ 3062.575004] ieee80211 phy3: brcmf_netdev_open: failed to bring up cfg80211

@Johnnie390
Copy link
Author

Pip,

any further ideas?

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 28, 2021

Hmm. No really good ones, at the moment. I tried with the mac address that was used on your system, to exclude that last possibility that that was the significant difference, but it just worked here.

Any idea how often it happens to work or fail?

Once I get back to the mini, I'll try rebooting it in a loop to see whether I can ever catch it failing to bring up the brcmfmac module...

@Johnnie390
Copy link
Author

Pip,

I have booted the machine to macos and back here (Linux) again to see if perhaps a firmware update might change things.
Nothing. On reboot, still no wlan0.

Ry

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 29, 2021

Pip,

performed an init 0 and power off. Lo and behold, wlan0 has surfaced.
When I issue a iwconfig wlan0 power off however, I receive these messages -
Error for wireless request "Set Power Management" (8B2C) :
SET failed on device wlan0 ; Cannot allocate memory.
and this in dmesg -
Wed Dec 29 10:48:56 2021] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 27 (26), ring 0
[Wed Dec 29 10:48:56 2021] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[Wed Dec 29 10:48:56 2021] ieee80211 phy2: brcmf_cfg80211_set_power_mgmt: error (-12)
[Wed Dec 29 10:48:56 2021] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 27 (26), ring 0
[Wed Dec 29 10:48:56 2021] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[Wed Dec 29 10:48:56 2021] ieee80211 phy2: brcmf_cfg80211_set_power_mgmt: Unable to set pm timeout, (-12)

@Johnnie390
Copy link
Author

Pip,

again, another shutdown and power off/on.

The device is not stable and cannot be varied online i.e. with an IP address, DHCP etc.
It would seem to be running out of it's memory allocation -
Look at this sequence (excerpt from dmesg) -

[Wed Dec 29 13:33:47 2021] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[Wed Dec 29 13:33:47 2021] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-5)
[Wed Dec 29 13:33:47 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 24 (27), ring 0
[Wed Dec 29 13:33:47 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Wed Dec 29 13:33:49 2021] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[Wed Dec 29 13:33:49 2021] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-5)
[Wed Dec 29 13:33:49 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 25 (27), ring 0
[Wed Dec 29 13:33:49 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Wed Dec 29 13:33:51 2021] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[Wed Dec 29 13:33:51 2021] brcmfmac: brcmf_pcie_ring_mb_write_wptr W w_ptr 26 (27), ring 0
[Wed Dec 29 13:33:51 2021] brcmfmac: brcmf_pcie_ring_mb_ring_bell RING !
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_msgbuf_query_dcmd: Timeout on response for query command
[Wed Dec 29 13:33:53 2021] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 27 (26), ring 0
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_dongle_scantime: Scan assoc time error (-12)
[Wed Dec 29 13:33:53 2021] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 27 (26), ring 0
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_netdev_open: failed to bring up cfg80211
[Wed Dec 29 13:33:53 2021] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 27 (26), ring 0
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_cfg80211_get_tx_power: error (-12)
[Wed Dec 29 13:33:53 2021] brcmfmac: brcmf_pcie_ring_mb_update_rptr R r_ptr 27 (26), ring 0
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_msgbuf_tx_ioctl: Failed to reserve space in commonring
[Wed Dec 29 13:33:53 2021] ieee80211 phy2: brcmf_cfg80211_get_channel: chanspec failed (-12)

Pip, are you also running a 5.16.0-rc6 kernel on the M1 Mini?

Ry

@Johnnie390
Copy link
Author

Just came across this - https://lore.kernel.org/all/20211226153624.162281-1-marcan@marcan.st/T/
Would this help us in our endeavours?

@pipcet
Copy link
Owner
pipcet commented Dec 29, 2021

Quite possibly! I'll have a look soon!

@Johnnie390
Copy link
Author

Fascinating.. what happens behind the scenes.

@Johnnie390
Copy link
Author
Johnnie390 commented Dec 30, 2021

Pip,

have prepared things as per instructions here https://lore.kernel.org/all/20211226153624.162281-1-marcan@marcan.st/T/.
The same (unfortunate) result again -

[Thu Dec 30 11:45:23 2021] brcmfmac: brcmf_pcie_register Enter
[Thu Dec 30 11:45:23 2021] brcmfmac 0000:01:00.0: of_irq_parse_pci: failed with rc=-22
[Thu Dec 30 11:45:23 2021] brcmfmac: brcmf_pcie_probe Enter 14e4:4425
[Thu Dec 30 11:45:23 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : reg space = ffff800014dc8000 base addr 0x000006c0c00000
[Thu Dec 30 11:45:23 2021] brcmfmac: brcmf_pcie_get_resource Phys addr : mem space = ffff800025000000 base addr 0x000006c0000000 size 0x800000
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 's=B1'
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'M=RASP'
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'm=6.11'
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element ''
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_process_otp_tuple system vendor OTP element 'V=m'
[Thu Dec 30 11:45:24 2021] brcmfmac 0000:01:00.0: module revision data: chip 4378, chip rev B1, module RASP, module rev 6.11, vendor m
[Thu Dec 30 11:45:24 2021] brcmfmac 0000:01:00.0: module serial number: 0c06f00020e53d76
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac4378-pcie for chip BCM4378/3
[Thu Dec 30 11:45:24 2021] brcmfmac 0000:01:00.0: Direct firmware load for brcm/brcmfmac4378-pcie.apple,j274.txt failed with error -2
[Thu Dec 30 11:45:24 2021] brcmfmac 0000:01:00.0: Falling back to sysfs fallback for: brcm/brcmfmac4378-pcie.apple,j274.txt
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_download_fw_nvram Halt ARM.
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download FW brcm/brcmfmac4378-pcie.bin 0x352000 0x14866a
[Thu Dec 30 11:45:24 2021] NVRAM:00000000: 6163616d 3d726464 653a3631 61613a65 macaddr=16:ee:aa
[Thu Dec 30 11:45:24 2021] NVRAM:00000010: 3a34623a 663a3363 564e0064 524d4152 :b4:c3:fd.NVRAMR
[Thu Dec 30 11:45:24 2021] NVRAM:00000020: 243d7665 3a766552 35323920 20373432 ev=$Rev: 925247
[Thu Dec 30 11:45:24 2021] NVRAM:00000030: 72730024 65726d6f 31313d76 616f6200 $.sromrev=11.boa
[Thu Dec 30 11:45:24 2021] NVRAM:00000040: 65726472 78303d76 30303631 616f6200 rdrev=0x1600.boa
.
.
.
[Thu Dec 30 11:45:24 2021] NVRAM:00001e00: 75745f65 676e696e 0000313d 00000000 e_tuning=1......
[Thu Dec 30 11:45:24 2021] NVRAM:00001e10: 00000000 f87a0785 ......z.
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_download_fw_nvram Download NVRAM brcm/brcmfmac4378-pcie.txt 0x51e1e8 0x1e18
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_download_fw_nvram Bring ARM in running state (RAM sign: 0xf87a0785)
[Thu Dec 30 11:45:24 2021] brcmfmac: brcmf_pcie_download_fw_nvram Wait for FW init
[Thu Dec 30 11:45:30 2021] brcmfmac 0000:01:00.0: brcmf_pcie_download_fw_nvram: FW failed to initialize
[Thu Dec 30 11:45:30 2021] brcmfmac: brcmf_pcie_remove Enter

Wireless works on macos, I am presuming all of the "correct" firmware is in the right place. Just wondering whether there is a mis-match/compatibility problem with the wireless firmware and the 5.16.0-rc6 kernel I am using...

root@magalas:/Transit/brcm# ll /lib/firmware/brcm
total 1388
20 drwxr-xr-x 2 root root 20480 Dec 30 11:43 .
4 drwxrwxrwx 29 root root 4096 Dec 30 10:01 ..
1316 -rw-r--r-- 1 root root 1345130 Jan 1 1970 brcmfmac4378-pcie.apple,j274.bin
8 -rw-r--r-- 1 root root 7570 Jan 1 1970 brcmfmac4378-pcie.apple,j274.txt
36 -rw-r--r-- 1 root root 33493 Jan 1 1970 brcmfmac4378-pcie.clm_blob
4 -rw-r--r-- 1 root root 304 Jan 1 1970 brcmfmac4378-pcie.txcb

Ry

@Johnnie390
Copy link
Author

Pip,

any developments from your side?

Ry

@pipcet
Copy link
Owner
pipcet commented Dec 31, 2021

I'll try preparing a kernel using marcan's driver, but it might not work out today...

@Johnnie390
Copy link
Author

I have tried the method outlined here https://lore.kernel.org/all/20211226153624.162281-1-marcan@marcan.st/T/ and renamed the files accordingly on the Linux side. Still the same error(s).
Good luck!

@Johnnie390
Copy link
Author

The last startup log of 2021.
Again, the wireless interface is in a twilight zone condition.

brcmf-startup-31.12.21.txt

@pipcet
Copy link
Owner
pipcet commented Jan 4, 2022

Sorry, I won't be getting around to this for at least another few days. Other stuff intervening...

@Johnnie390
Copy link
Author

Understand.

@Johnnie390
Copy link
Author

Very quiet here..

@Johnnie390
Copy link
Author

Hello Pip,

will there be any more updates here?

Regards

Ry

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants
0