This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

WL1837MOD: WiFi fails after days or weeks. Reboot does *not* recover - requires power off.

Part Number: WL1837MOD
Other Parts Discussed in Thread: WL1271, TCA6408, WL1837, WL1831

Running under Linux kernel 5.4 on embedded device (Xilinx Zynq 7020, armhf), Ubuntu 20.04.3 LTS.

After operating properly for several days, my WiFi connection dropped, and syslog showed these messages:

Nov 02 15:02:03 MPM4-6001 kernel: wl1271_sdio mmc1:0001:2: sdio write failed (-110)

Nov 02 15:02:03 MPM4-6001 kernel: wlcore: WARNING Enable for recovery failed

Nov 02 15:02:03 MPM4-6001 kernel: wlcore: down

Nov 02 15:02:03 MPM4-6001 kernel: wlcore: down

Nov 02 15:02:03 MPM4-6001 kernel: ieee80211 phy0: Hardware restart was requested

Nov 02 15:02:04 MPM4-6001 kernel: wl1271_sdio mmc1:0001:2: wl12xx_sdio_power_on: failed to get_sync(-110)

Nov 02 15:02:04 MPM4-6001 kernel: wl1271_sdio mmc1:0001:2: wl12xx_sdio_power_on: failed to get_sync(-22)

Nov 02 15:02:04 MPM4-6001 kernel: wl1271_sdio mmc1:0001:2: wl12xx_sdio_power_on: failed to get_sync(-22)

Nov 02 15:02:04 MPM4-6001 kernel: wlcore: ERROR firmware boot failed despite 3 retries

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: deauthenticating from c0:36:53:73:00:85 by local choice (Reason: 3=DEAUTH_LEAVING)

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: HW problem - can not stop rx aggregation for c0:36:53:73:00:85 tid 0

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: HW problem - can not stop rx aggregation for c0:36:53:73:00:85 tid 1

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: HW problem - can not stop rx aggregation for c0:36:53:73:00:85 tid 6

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: failed to remove key (0, c0:36:53:73:00:85) from hardware (-5)

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-5)

Nov 02 15:02:04 MPM4-6001 kernel: wlan0: failed to remove key (2, ff:ff:ff:ff:ff:ff) from hardware (-5)

Nov 02 15:02:04 MPM4-6001 wpa_supplicant[229]: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:36:53:73:00:85 reason=3 locally_generated=1

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Interface wlan0.IPv6 no longer relevant for mDNS.

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.

Nov 02 15:02:04 MPM4-6001 systemd-networkd[197]: wlan0: Link DOWN

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Interface wlan0.IPv4 no longer relevant for mDNS.

Nov 02 15:02:04 MPM4-6001 wpa_supplicant[229]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.

Nov 02 15:02:04 MPM4-6001 avahi-daemon[251]: Withdrawing address record for 192.168.4.103 on wlan0.

Nov 02 15:02:04 MPM4-6001 systemd-networkd[197]: wlan0: Lost carrier

Nov 02 15:02:04 MPM4-6001 systemd-networkd[197]: wlan0: DHCP lease lost

  • WL_EN goes low
  • Network interface (wlan0) no longer appears in output of "ip link"
  • wlan0 disappears from /sys/class/net
  • phy0 disappears from /sys/kernel/debug/ieee80211
  • cat /sys/class/net/wlan0/device/power/runtime_status returns "failed".

Rebooting does not recover from this condition - only removing power from the device returns normal operation.

WL_EN goes high momentarily during reboot, then returns low.

Normal (before failure) boot shows these messages in syslog:

Mar 2 12:58:11 localhost systemd-modules-load[147]: Inserted module 'wl18xx'
Mar 2 12:58:11 localhost kernel: [ 9.102380] wl18xx_driver wl18xx.0.auto: Direct firmware load for ti-connectivity/wl1271-nvs.bin failed with error -2
Mar 2 12:58:11 localhost kernel: [ 9.638664] wlcore: wl18xx HW: 183x or 180x, PG 2.2 (ROM 0x11)
Mar 2 12:58:11 localhost kernel: [ 9.657138] wlcore: loaded
Mar 2 12:58:11 localhost kernel: [ 12.261223] wlcore: PHY firmware version: Rev 8.2.0.0.236
Mar 2 12:58:11 localhost kernel: [ 12.361951] wlcore: firmware booted (Rev 8.9.0.0.69)

This happens irregularly, but frequently, with days passing between failures. Needless to say this is a catastrophic failure, requiring an in-person visit to the device's location in order to "turn it off and back on again." Not a good look.

Any help would be appreciated.

  • Hi Nick,

    The firmware version you are using is quite old, can you update it to 8.9.0.0.90 and try again?

    Here is a link to the specific commit for .90: https://git.ti.com/cgit/wilink8-wlan/wl18xx_fw/tree/?id=d2588c16809ecca8e0dc7ea011fc6180c7b08a92

    Using the very latest FW requires a driver patch also, hence this version.

  • Hi .

    Is what I've described a known problem with the .86 firmwar?

    I'm happy to update the driver as well - can you tell me where to find patch instructions and the newest firmware?

    Thanks,

    -Nick

  • Hi NIck,

    We have patches, but those patches were created for kernel 4.19. This guide walks you through how to build and compile patches: https://www.ti.com/lit/swru561 

    Although the guide was intended for TI devices, they should also apply to your device since the kernel driver is similar, noting the kernel version difference. 

  • Hi .

    Since it can take many weeks for this problem to manifest, what can I do before power-cycling my device to gain some insight into what has failed? As mentioned, rebooting doesn't recover the WiLink chip. WL_EN goes high momentarily during reboot, then returns low. The chip doesn't seem to be detected at all, so the diagnostics normally provided by the driver are unavailable. 

    Is there anything that can be learned with the chip in this state? Given the very long MTBF, the practice of making changes and observing the result isn't an attractive option.

    Thanks again,

    -Nick

  • Hi Nick,

    It is interest that reboot does not recover the WiLink chip, even after WL_EN goes high and low. In this state, can you provide the full dmesg logs of a reboot?

    I would like to confirm correct operation, as much as I can tell before you do a power reset. 

  • Hi .

    The output of the dmesg command is missing some of the initial console output. I've included that output ahead of the actual dmesg output below.

    Thanks,

    -Nick

    (Captured console output)


    [ 0.737206] kernel: PTP clock support registered
    [ 0.741123] kernel: EDAC MC: Ver: 3.0.0
    [ 0.744971] kernel: FPGA manager framework
    [ 0.750230] kernel: clocksource: Switched to clocksource arm_global_timer
    [ 1.459588] kernel: VFS: Disk quotas dquot_6.6.0
    [ 1.463671] kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
    [ 1.470823] kernel: FS-Cache: Loaded
    [ 1.473999] kernel: CacheFiles: Loaded
    [ 1.492031] kernel: NET: Registered protocol family 2
    [ 1.497257] kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
    [ 1.505702] kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
    [ 1.513555] kernel: TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
    [ 1.520821] kernel: TCP: Hash tables configured (established 8192 bind 8192)
    [ 1.527339] kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
    [ 1.534027] kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
    [ 1.541504] kernel: NET: Registered protocol family 1
    [ 1.546888] kernel: RPC: Registered named UNIX socket transport module.
    [ 1.552845] kernel: RPC: Registered udp transport module.
    [ 1.557550] kernel: RPC: Registered tcp transport module.
    [ 1.562264] kernel: RPC: Registered tcp NFSv4.1 backchannel transport module.
    [ 1.568715] kernel: PCI: CLS 0 bytes, default 64
    [ 1.573496] kernel: hw perfevents: no interrupt-affinity property for /pmu@f8891000, guessing.
    [ 1.581837] kernel: hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
    [ 1.592426] kernel: Initialise system trusted keyrings
    [ 1.597118] kernel: workingset: timestamp_bits=30 max_order=18 bucket_order=0
    [ 1.604656] kernel: FS-Cache: Netfs 'nfs' registered for caching
    [ 1.610547] kernel: NFS: Registering the id_resolver key type
    [ 1.615627] kernel: Key type id_resolver registered
    [ 1.619813] kernel: Key type id_legacy registered
    [ 1.623914] kernel: jffs2: version 2.2. (NAND) (SUMMARY) © 2001-2006 Red Hat, Inc.
    [ 1.666917] kernel: Key type asymmetric registered
    [ 1.671069] kernel: Asymmetric key parser 'x509' registered
    [ 1.675969] kernel: io scheduler mq-deadline registered
    [ 1.680559] kernel: io scheduler kyber registered
    [ 1.685545] kernel: zynq-pinctrl 700.pinctrl: zynq pinctrl initialized
    [ 1.692191] kernel: gpiochip_find_base: found new base at 906
    [ 1.692553] kernel: gpio gpiochip0: (zynq_gpio): added GPIO chardev (254:0)
    [ 1.692699] kernel: gpiochip_setup_dev: registered GPIOs 906 to 1023 on device: gpiochip0 (zynq_gpio)
    [ 1.696302] kernel: dma-pl330 f8003000.dmac: Loaded driver for PL330 DMAC-241330
    [ 1.703079] kernel: dma-pl330 f8003000.dmac: DBUFF-128x8bytes Num_Chans-8 Num_Peri-4 Num_Events-16
    [ 1.712298] kernel: Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
    [ 1.734494] kernel: brd: module loaded
    [ 1.753025] kernel: loop: module loaded
    [ 1.761806] kernel: spi-nor spi0.0: n25q128a11 (16384 Kbytes)
    [ 1.766996] kernel: 5 fixed-partitions partitions found on MTD device spi0.0
    [ 1.773388] kernel: Creating 5 MTD partitions on "spi0.0":
    [ 1.778196] kernel: 0x000000000000-0x000000080000 : "qspi-fsbl-uboot"
    [ 1.791790] kernel: 0x000000080000-0x000000480000 : "qspi-linux"
    [ 1.802628] kernel: 0x000000480000-0x000000490000 : "qspi-device-tree"
    [ 1.811780] kernel: 0x000000490000-0x000000d80000 : "qspi-rootfs"
    [ 1.822628] kernel: 0x000000d80000-0x000001000000 : "qspi-bitstream"
    [ 1.832428] kernel: mdio_bus fixed-0: GPIO lookup for consumer reset
    [ 1.832444] kernel: mdio_bus fixed-0: using lookup tables for GPIO lookup
    [ 1.832459] kernel: mdio_bus fixed-0: No GPIO consumer reset found
    [ 1.832495] kernel: libphy: Fixed MDIO Bus: probed
    [ 1.838248] kernel: mdio_bus e000b000.ethernet-ffffffff: GPIO lookup for consumer reset
    [ 1.838264] kernel: mdio_bus e000b000.ethernet-ffffffff: using device tree for GPIO lookup
    [ 1.838330] kernel: of_get_named_gpiod_flags: parsed 'reset-gpios' property of node '/amba/ethernet@e000b000[0]' - status (0)
    [ 1.838403] kernel: libphy: MACB_mii_bus: probed
    [ 1.860671] kernel: mdio_bus e000b000.ethernet-ffffffff:00: GPIO lookup for consumer reset
    [ 1.860687] kernel: mdio_bus e000b000.ethernet-ffffffff:00: using lookup tables for GPIO lookup
    [ 1.860702] kernel: mdio_bus e000b000.ethernet-ffffffff:00: No GPIO consumer reset found
    [ 2.501099] kernel: Generic PHY e000b000.ethernet-ffffffff:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=e000b000.ethernet-ffffffff:00, irq=POLL)
    [ 2.514343] kernel: macb e000b000.ethernet eth0: Cadence GEM rev 0x00020118 at 0xe000b000 irq 29 (70:b3:d5:ef:10:62)
    [ 2.524951] kernel: uio_pdrv_genirq 44a00000.core100_adc: IRQ index 0 not found
    [ 2.534981] kernel: uio_pdrv_genirq 3fe00000.core100_sd_buffer: IRQ index 0 not found
    [ 2.543438] kernel: mousedev: PS/2 mouse device common for all mice
    [ 2.549543] kernel: i2c /dev entries driver
    [ 2.554353] kernel: at24 0-0050: GPIO lookup for consumer wp
    [ 2.554369] kernel: at24 0-0050: using device tree for GPIO lookup
    [ 2.554409] kernel: of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/i2c@e0004000/m24lc32b@50[0]'
    [ 2.554443] kernel: of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/i2c@e0004000/m24lc32b@50[0]'
    [ 2.554465] kernel: at24 0-0050: using lookup tables for GPIO lookup
    [ 2.554480] kernel: at24 0-0050: No GPIO consumer wp found
    [ 2.554913] kernel: at24 0-0050: 4096 byte 24c32 EEPROM, writable, 1 bytes/write
    [ 2.562512] kernel: cdns-i2c e0004000.i2c: 400 kHz mmio e0004000 irq 22
    [ 2.569606] kernel: cdns-i2c e0005000.i2c: 400 kHz mmio e0005000 irq 23
    [ 2.576089] kernel: Driver for 1-wire Dallas network protocol.
    [ 2.586497] kernel: cdns-wdt f8005000.watchdog: Xilinx Watchdog Timer with timeout 10s
    [ 2.594413] kernel: EDAC MC: ECC not enabled
    [ 2.601255] kernel: Xilinx Zynq CpuIdle Driver started
    [ 2.604730] kernel: random: fast init done
    [ 2.606587] kernel: sdhci: Secure Digital Host Controller Interface driver
    [ 2.615397] kernel: sdhci: Copyright(c) Pierre Ossman
    [ 2.619758] kernel: sdhci-pltfm: SDHCI platform and OF driver helper
    [ 2.626034] kernel: sdhci-arasan e0100000.sdhci: GPIO lookup for consumer cd
    [ 2.626050] kernel: sdhci-arasan e0100000.sdhci: using device tree for GPIO lookup
    [ 2.626092] kernel: of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/amba/sdhci@e0100000[0]'
    [ 2.626128] kernel: of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/amba/sdhci@e0100000[0]'
    [ 2.626151] kernel: sdhci-arasan e0100000.sdhci: using lookup tables for GPIO lookup
    [ 2.626165] kernel: sdhci-arasan e0100000.sdhci: No GPIO consumer cd found
    [ 2.626183] kernel: sdhci-arasan e0100000.sdhci: GPIO lookup for consumer wp
    [ 2.626196] kernel: sdhci-arasan e0100000.sdhci: using device tree for GPIO lookup
    [ 2.626231] kernel: of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/sdhci@e0100000[0]'
    [ 2.626265] kernel: of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/sdhci@e0100000[0]'
    [ 2.626286] kernel: sdhci-arasan e0100000.sdhci: using lookup tables for GPIO lookup
    [ 2.626299] kernel: sdhci-arasan e0100000.sdhci: No GPIO consumer wp found
    [ 2.645121] kernel: w1_master_driver w1_bus_master5: Attaching one wire slave 3d.000001171c05 crc 8f
    [ 2.653976] kernel: w1_master_driver w1_bus_master5: Family 3d for 3d.000001171c05.8f is not registered.
    [ 2.681140] kernel: mmc0: SDHCI controller on e0100000.sdhci [e0100000.sdhci] using ADMA
    [ 2.688985] kernel: sdhci-arasan e0101000.sdhci: GPIO lookup for consumer cd
    [ 2.689000] kernel: sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    [ 2.689052] kernel: of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/amba/sdhci@e0101000[0]'
    [ 2.689088] kernel: of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/amba/sdhci@e0101000[0]'
    [ 2.689110] kernel: sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    [ 2.689124] kernel: sdhci-arasan e0101000.sdhci: No GPIO consumer cd found
    [ 2.689141] kernel: sdhci-arasan e0101000.sdhci: GPIO lookup for consumer wp
    [ 2.689153] kernel: sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    [ 2.689188] kernel: of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/sdhci@e0101000[0]'
    [ 2.689222] kernel: of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/sdhci@e0101000[0]'
    [ 2.689243] kernel: sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    [ 2.689258] kernel: sdhci-arasan e0101000.sdhci: No GPIO consumer wp found
    [ 2.690088] kernel: clocksource: ttc_clocksource: mask: 0xffff max_cycles: 0xffff, max_idle_ns: 413490550 ns
    [ 2.699472] kernel: timer #0 at (ptrval), irq=43
    [ 2.705408] kernel: fpga_manager fpga0: Xilinx Zynq FPGA Manager registered
    [ 2.713060] kernel: NET: Registered protocol family 10
    [ 2.719229] kernel: Segment Routing with IPv6
    [ 2.723064] kernel: sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
    [ 2.730008] kernel: NET: Registered protocol family 17
    [ 2.734604] kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
    [ 2.747972] kernel: sctp: Hash tables configured (bind 512/512)
    [ 2.753525] kernel: Key type dns_resolver registered
    [ 2.758258] kernel: Registering SWP/SWPB emulation handler
    [ 2.763412] kernel: Loading compiled-in X.509 certificates
    [ 2.769865] kernel: Key type encrypted registered
    [ 2.785614] kernel: mmc0: new high speed SDXC card at address aaaa
    [ 2.798930] kernel: reg-fixed-voltage fixed-regulator-wlen: GPIO lookup for consumer (null)
    [ 2.798948] kernel: reg-fixed-voltage fixed-regulator-wlen: using device tree for GPIO lookup
    [ 2.798993] kernel: of_get_named_gpiod_flags: can't parse 'gpios' property of node '/fixed-regulator-wlen[0]'
    [ 2.799054] kernel: of_get_named_gpiod_flags: parsed 'gpio' property of node '/fixed-regulator-wlen[0]' - status (0)
    [ 2.800123] kernel: sdhci-arasan e0101000.sdhci: GPIO lookup for consumer cd
    [ 2.800139] kernel: sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    [ 2.800308] kernel: of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/amba/sdhci@e0101000[0]'
    [ 2.800347] kernel: of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/amba/sdhci@e0101000[0]'
    [ 2.800372] kernel: sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    [ 2.800388] kernel: sdhci-arasan e0101000.sdhci: No GPIO consumer cd found
    [ 2.800405] kernel: sdhci-arasan e0101000.sdhci: GPIO lookup for consumer wp

    (Output of dmesg command)

    root@MPM4-6001:~# dmesg
    [ 2.800405] sdhci-arasan e0101000.sdhci: GPIO lookup for consumer wp
    [ 2.800418] sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    [ 2.800455] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/sdhci@e0101000[0]'
    [ 2.800489] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/sdhci@e0101000[0]'
    [ 2.800510] sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    [ 2.800524] sdhci-arasan e0101000.sdhci: No GPIO consumer wp found
    [ 2.802427] mmcblk0: mmc0:aaaa SD256 238 GiB
    [ 2.830643] mmcblk0: p1 p2
    [ 2.935352] mmc1: SDHCI controller on e0101000.sdhci [e0101000.sdhci] using ADMA
    [ 2.943447] of_cfs_init
    [ 2.946082] of_cfs_init: OK
    [ 3.042187] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
    [ 3.050437] VFS: Mounted root (ext4 filesystem) on device 179:2.
    [ 3.058617] devtmpfs: mounted
    [ 3.069736] Freeing unused kernel memory: 1024K
    [ 3.074757] Run /sbin/init as init process
    [ 3.647814] systemd[1]: System time before build time, advancing clock.
    [ 3.798339] systemd[1]: systemd 245.4-4ubuntu3.22 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
    [ 3.821905] systemd[1]: Detected architecture arm.
    [ 3.871729] systemd[1]: Set hostname to <MPM4-6001>.
    [ 4.952004] random: systemd: uninitialized urandom read (16 bytes read)
    [ 4.958939] systemd[1]: system-modprobe.slice: unit configures an IP firewall, but the local system does not support BPF/cgroup firewalling.
    [ 4.971620] systemd[1]: (This warning is only shown for the first unit using IP firewalling.)
    [ 4.981657] systemd[1]: Created slice system-modprobe.slice.
    [ 5.020471] random: systemd: uninitialized urandom read (16 bytes read)
    [ 5.027983] systemd[1]: Created slice system-serial\x2dgetty.slice.
    [ 5.070584] random: systemd: uninitialized urandom read (16 bytes read)
    [ 5.077931] systemd[1]: Created slice User and Session Slice.
    [ 5.110978] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
    [ 5.150903] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
    [ 5.190724] systemd[1]: Condition check resulted in Arbitrary Executable File Formats File System Automount Point being skipped.
    [ 5.202722] systemd[1]: Reached target Local Encrypted Volumes.
    [ 5.240672] systemd[1]: Reached target Paths.
    [ 5.270522] systemd[1]: Reached target Remote File Systems.
    [ 5.310490] systemd[1]: Reached target Slices.
    [ 5.340525] systemd[1]: Reached target Swap.
    [ 5.371475] systemd[1]: Listening on Syslog Socket.
    [ 5.400981] systemd[1]: Listening on initctl Compatibility Named Pipe.
    [ 5.458871] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
    [ 5.468159] systemd[1]: Listening on Journal Socket (/dev/log).
    [ 5.501561] systemd[1]: Listening on Journal Socket.
    [ 5.531534] systemd[1]: Listening on udev Control Socket.
    [ 5.571138] systemd[1]: Listening on udev Kernel Socket.
    [ 5.611197] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
    [ 5.624970] systemd[1]: Mounting POSIX Message Queue File System...
    [ 5.666902] systemd[1]: Mounting Kernel Debug File System...
    [ 5.706164] systemd[1]: Mounting Kernel Trace File System...
    [ 5.745999] systemd[1]: Starting Journal Service...
    [ 5.786388] systemd[1]: Starting Set the console keyboard layout...
    [ 5.825944] systemd[1]: Starting Create list of static device nodes for the current kernel...
    [ 5.876091] systemd[1]: Starting Load Kernel Module chromeos_pstore...
    [ 5.902795] systemd[1]: Starting Load Kernel Module drm...
    [ 5.936361] systemd[1]: Starting Load Kernel Module efi_pstore...
    [ 5.986248] systemd[1]: Starting Load Kernel Module pstore_blk...
    [ 6.026026] systemd[1]: Starting Load Kernel Module pstore_zone...
    [ 6.076181] systemd[1]: Starting Load Kernel Module ramoops...
    [ 6.110722] systemd[1]: Condition check resulted in OpenVSwitch configuration for cleanup being skipped.
    [ 6.123542] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
    [ 6.141906] systemd[1]: Starting Load Kernel Modules...
    [ 6.175649] systemd[1]: Starting Remount Root and Kernel File Systems...
    [ 6.212185] systemd[1]: Starting udev Coldplug all Devices...
    [ 6.247979] systemd[1]: Starting Uncomplicated firewall...
    [ 6.303418] systemd[1]: Started Journal Service.
    [ 6.312275] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
    [ 6.645420] cfg80211: Loading compiled-in X.509 certificates for regulatory database
    [ 6.689318] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
    [ 7.114750] systemd-journald[142]: Received client request to flush runtime journal.
    [ 7.457106] systemd-journald[142]: File /var/log/journal/9f57996f609e492eb54aa5924d217b3f/system.journal corrupted or uncleanly shut down, renaming and replacing.
    [ 9.142597] pca953x 0-0020: GPIO lookup for consumer reset
    [ 9.142618] pca953x 0-0020: using device tree for GPIO lookup
    [ 9.142663] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/amba/i2c@e0004000/tca6408@20[0]'
    [ 9.142698] of_get_named_gpiod_flags: can't parse 'reset-gpio' property of node '/amba/i2c@e0004000/tca6408@20[0]'
    [ 9.142721] pca953x 0-0020: using lookup tables for GPIO lookup
    [ 9.142736] pca953x 0-0020: No GPIO consumer reset found
    [ 9.142777] pca953x 0-0020: 0-0020 supply vcc not found, using dummy regulator
    [ 9.161276] gpiochip_find_base: found new base at 898
    [ 9.162026] gpio gpiochip1: (0-0020): added GPIO chardev (254:1)
    [ 9.162217] gpiochip_setup_dev: registered GPIOs 898 to 905 on device: gpiochip1 (0-0020)
    [ 9.278719] pcf85363 0-0051: registered as rtc0
    [ 9.388295] usbcore: registered new interface driver usbfs
    [ 9.388437] usbcore: registered new interface driver hub
    [ 9.411633] bno055 1-0028: selected mode 0x0c
    [ 9.411658] bno055 1-0028: axis map: x,y,z
    [ 9.411675] bno055 1-0028: temperature unit: celsius
    [ 9.411692] bno055 1-0028: Euler unit not specified: -22
    [ 9.411707] bno055 1-0028: gyro unit: rps
    [ 9.411722] bno055 1-0028: accel unit: mps2
    [ 9.411738] bno055 1-0028: rotation convention: windows
    [ 9.461249] usbcore: registered new device driver usb
    [ 9.473805] bno055 1-0028: software revision id 0311
    [ 9.594687] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
    [ 9.788744] core100: core100_driver_init()
    [ 9.788769] core100: allocated chrdev region: Major: 245, Minor: 0-8
    [ 9.789109] core100_probe()
    [ 9.789129] core100: create_devices()
    [ 9.789188] core100 core100_dma: GPIO lookup for consumer dma-irq
    [ 9.789202] core100 core100_dma: using device tree for GPIO lookup
    [ 9.789273] of_get_named_gpiod_flags: parsed 'dma-irq-gpios' property of node '/core100_dma[0]' - status (0)
    [ 9.807585] usb_phy_generic phy0: GPIO lookup for consumer reset
    [ 9.807606] usb_phy_generic phy0: using device tree for GPIO lookup
    [ 9.807678] of_get_named_gpiod_flags: parsed 'reset-gpios' property of node '/phy0[0]' - status (0)
    [ 9.807711] no flags found for reset
    [ 9.807730] usb_phy_generic phy0: GPIO lookup for consumer vbus-detect
    [ 9.807743] usb_phy_generic phy0: using device tree for GPIO lookup
    [ 9.807779] of_get_named_gpiod_flags: can't parse 'vbus-detect-gpios' property of node '/phy0[0]'
    [ 9.807813] of_get_named_gpiod_flags: can't parse 'vbus-detect-gpio' property of node '/phy0[0]'
    [ 9.807834] usb_phy_generic phy0: using lookup tables for GPIO lookup
    [ 9.807848] usb_phy_generic phy0: No GPIO consumer vbus-detect found
    [ 9.807909] usb_phy_generic phy0: phy0 supply vcc not found, using dummy regulator
    [ 9.827908] core100: raw_dma available
    [ 9.831749] core100 core100_dma: GPIO lookup for consumer dma-irq
    [ 9.831764] core100 core100_dma: using device tree for GPIO lookup
    [ 9.831842] of_get_named_gpiod_flags: parsed 'dma-irq-gpios' property of node '/core100_dma[1]' - status (0)
    [ 9.834928] core100: resampler_dma available
    [ 9.839233] core100 core100_dma: GPIO lookup for consumer dma-irq
    [ 9.839248] core100 core100_dma: using device tree for GPIO lookup
    [ 9.839327] of_get_named_gpiod_flags: parsed 'dma-irq-gpios' property of node '/core100_dma[2]' - status (0)
    [ 9.873769] core100: iir_dma available
    [ 9.877554] core100 core100_dma: GPIO lookup for consumer dma-irq
    [ 9.877568] core100 core100_dma: using device tree for GPIO lookup
    [ 9.877656] of_get_named_gpiod_flags: parsed 'dma-irq-gpios' property of node '/core100_dma[3]' - status (0)
    [ 9.904266] core100: fir1_dma available
    [ 9.908144] core100 core100_dma: GPIO lookup for consumer dma-irq
    [ 9.908159] core100 core100_dma: using device tree for GPIO lookup
    [ 9.908258] of_get_named_gpiod_flags: parsed 'dma-irq-gpios' property of node '/core100_dma[4]' - status (0)
    [ 9.941464] core100: fir2_dma available
    [ 9.960631] pps pps0: new PPS source core100
    [ 10.020151] chipidea-usb2 e0002000.usb: e0002000.usb supply vbus not found, using dummy regulator
    [ 10.089319] ci_hdrc ci_hdrc.0: EHCI Host Controller
    [ 10.089400] ci_hdrc ci_hdrc.0: new USB bus registered, assigned bus number 1
    [ 10.270327] ci_hdrc ci_hdrc.0: USB 2.0 started, EHCI 1.00
    [ 10.271305] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
    [ 10.271324] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [ 10.271338] usb usb1: Product: EHCI Host Controller
    [ 10.271352] usb usb1: Manufacturer: Linux 5.4.0-nanotok-00012-g9a7baa1bf81f-dirty ehci_hcd
    [ 10.271365] usb usb1: SerialNumber: ci_hdrc.0
    [ 10.272646] hub 1-0:1.0: USB hub found
    [ 10.272766] hub 1-0:1.0: 1 port detected
    [ 10.640285] usb 1-1: new high-speed USB device number 2 using ci_hdrc
    [ 10.766262] random: crng init done
    [ 10.766278] random: 7 urandom warning(s) missed due to ratelimiting
    [ 10.833552] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
    [ 10.850548] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
    [ 10.850601] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
    [ 10.860425] hub 1-1:1.0: USB hub found
    [ 10.860685] hub 1-1:1.0: 4 ports detected
    [ 11.180291] usb 1-1.2: new full-speed USB device number 3 using ci_hdrc
    [ 11.331925] usb 1-1.2: New USB device found, idVendor=1546, idProduct=01a8, bcdDevice= 3.01
    [ 11.331947] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
    [ 11.331960] usb 1-1.2: Product: u-blox GNSS receiver
    [ 11.331974] usb 1-1.2: Manufacturer: u-blox AG - www.u-blox.com
    [ 11.578762] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
    [ 11.580106] usbcore: registered new interface driver cdc_acm
    [ 11.580119] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
    [ 13.088394] gpio gpiochip1: Persistence not supported for GPIO 0
    [ 13.094790] gpio gpiochip1: Persistence not supported for GPIO 1
    [ 13.098152] gpio gpiochip1: Persistence not supported for GPIO 2
    [ 13.107621] gpio gpiochip1: Persistence not supported for GPIO 3
    [ 13.109677] gpio gpiochip1: Persistence not supported for GPIO 4
    [ 13.137757] gpio gpiochip1: Persistence not supported for GPIO 5
    [ 13.149615] gpio gpiochip1: Persistence not supported for GPIO 6
    [ 13.173380] usb 1-1: USB disconnect, device number 2
    [ 13.173413] usb 1-1.2: USB disconnect, device number 3
    [ 13.911997] w1_master_driver w1_bus_master5: Attaching one wire slave 3d.000001171c05 crc 8f
    [ 14.070350] usb 1-1: new high-speed USB device number 4 using ci_hdrc
    [ 14.271043] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
    [ 14.271081] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
    [ 14.272469] hub 1-1:1.0: USB hub found
    [ 14.274514] hub 1-1:1.0: 4 ports detected
    [ 17.960904] sched: RT throttling activated
    [ 19.293405] core100: core100_read(raw_dma)[891]: wait_event_interruptible_timeout() interrupted: 679
    [ 19.304499] core100: core100_read(resampler_dma)[891]: wait_event_interruptible_timeout() interrupted: 678
    [ 19.318379] core100: core100_read(iir_dma)[891]: wait_event_interruptible_timeout() interrupted: 678
    [ 19.328446] core100: core100_read(fir2_dma)[891]: wait_event_interruptible_timeout() interrupted: 997
    [ 19.642700] usb 1-1.2: new full-speed USB device number 5 using ci_hdrc
    [ 20.132887] usb 1-1.2: New USB device found, idVendor=1546, idProduct=01a8, bcdDevice= 3.01
    [ 20.132912] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
    [ 20.132936] usb 1-1.2: Product: u-blox GNSS receiver
    [ 20.132967] usb 1-1.2: Manufacturer: u-blox AG - www.u-blox.com
    [ 20.150431] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
    [ 22.120760] macb e000b000.ethernet eth0: link up (100/Full)
    [ 22.120811] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    [ 33.150270] wlan-en-regulator: disabling

  • Hey Nick

    What is strange about this log is that mmc1 probe does not detect the card at all. We should be seeing a print out of "mmc1: detected SDIO card at address xxx" or similar. Generally speaking, this would point to a hardware issue, but it's strange because it works on first power on.

    Are you sure WL_EN into the WL18x is toggling? By chance is there an issue with the state of SDIO lines on a reboot vs a full power cycle? 

  • Hi .

    This is the best capture I could get. The yellow trace is WL_EN. I used a one-shot trigger on a falling edge. 50 ms/division is as slow as I could go and still be able to use a one-shot trigger. Before and after this snapshot, WL_EN is low.

    As for the SDIO lines, anything is possible, given the circumstances. 

    The SDIO devicetree node is

    sdhci1: sdhci@e0101000 {
        compatible = "arasan,sdhci-8.9a";
        status = "okay";
        clock-names = "clk_xin", "clk_ahb";
        clocks = <&clkc 22>, <&clkc 33>;
        interrupt-parent = <&intc>;
        interrupts = <0 47 4>;
        reg = <0xe0101000 0x1000>;
        broken-adma2;
        vmmc-supply = <&wlan_en_reg>;
        bus-width = <4>;
        cap-power-off-card;
        keep-power-in-suspend;
        #address-cells = <1>;
        #size-cells = <0>;
        xlnx,has-cd = <0>;
        xlnx,has-power = <0>;
        xlnx,has-wp = <0>;

        wlcore: wlcore@0 {
            compatible = "wlcore", "ti,wl1831", "ti,wl1837";
            reg = <0x2>;
            interrupt-parent = <&gpio0>;
            interrupts = <0 4>;
        };
    };

    Unfortunately, the SDIO lines are not readily accessible. 

    Anything else we can look at?

    Thanks,

    -Nick

  • Are you able to probe CMD and CLK? 

  • CMD yes, CLK no.

    CMD does wiggle during boot (yellow trace again). I'll see if I can get a better capture at a higher speed...

  • Same thing at 1 ms/div.

  • On the other hand, the SDIO hardware is actually FPGA IP, and the FPGA is reset and its bitstream reloaded on reboot. So the likelihood of a problem with the SDIO signals is really pretty low.

  • I take it back - the SDIO interfaces are not FPGA IP, they're discrete components - just part of the SoC. They should be reset and reconfigured on boot, though, and the other SDIO interface is what the system reliably boots from.

  • Hi Nick,

    I am actually wondering if there is an issue with the Zynq SoC and its mmc drivers. A reboot in linux should bring up the driver without any problems, unless there is an issue in hardware with the WL_EN or something else (which is not the case as you are showing it toggling). Is the SLOW_CLK generated by the SoC or a designated CLK?

    Can you try unbind the mmc driver and binding it back in the failed and working states? 

  • Hi .

    I don't think so. There isn't an mmc device to bind.

    On device with a functional WiLink8, there are both an mmc and an sdio device. Here's an example of a working device:

    Working

    # ll /sys/bus/mmc/drivers/mmcblk/
    total 0
    drwxr-xr-x 2 root root 0 Mar 2 2023 ./
    drwxr-xr-x 3 root root 0 Mar 2 2023 ../
    --w------- 1 root root 4096 Nov 9 00:36 bind
    lrwxrwxrwx 1 root root 0 Nov 9 00:36 mmc0:aaaa -> ../../../../devices/soc0/amba/e0100000.sdhci/mmc_host/mmc0/mmc0:aaaa/
    --w------- 1 root root 4096 Mar 2 2023 uevent
    --w------- 1 root root 4096 Nov 9 00:36 unbind

    # ll /sys/devices/soc0/amba/e0101000.sdhci/mmc_host/mmc1
    total 0
    drwxr-xr-x 4 root root 0 Mar 2 2023 ./
    drwxr-xr-x 3 root root 0 Mar 2 2023 ../
    lrwxrwxrwx 1 root root 0 Nov 9 00:45 device -> ../../../e0101000.sdhci/
    drwxr-xr-x 5 root root 0 Mar 2 2023 mmc1:0001/
    drwxr-xr-x 2 root root 0 Nov 9 00:45 power/
    lrwxrwxrwx 1 root root 0 Mar 2 2023 subsystem -> ../../../../../../class/mmc_host/
    -rw-r--r-- 1 root root 4096 Mar 2 2023 uevent

    #ll /sys/bus/sdio/drivers/wl1271_sdio
    total 0
    drwxr-xr-x 2 root root 0 Mar 2 2023 ./
    drwxr-xr-x 3 root root 0 Mar 2 2023 ../
    --w------- 1 root root 4096 Nov 9 00:37 bind
    lrwxrwxrwx 1 root root 0 Nov 9 00:37 mmc1:0001:2 -> ../../../../devices/soc0/amba/e0101000.sdhci/mmc_host/mmc1/mmc1:0001/mmc1:0001:2/
    --w------- 1 root root 4096 Mar 2 2023 uevent
    --w------- 1 root root 4096 Nov 9 00:37 unbind

    And on the failed device...

    Failed

    # echo -n "mmc1:0001:2" > /sys/bus/sdio/drivers/wl1271_sdio/bind
    -bash: echo: write error: No such device

    # ll /sys/bus/mmc/drivers/mmcblk
    total 0
    drwxr-xr-x 2 root root 0 Mar 27 2023 ./
    drwxr-xr-x 3 root root 0 Mar 27 2023 ../
    --w------- 1 root root 4096 Nov 9 00:38 bind
    lrwxrwxrwx 1 root root 0 Nov 9 00:38 mmc0:aaaa -> ../../../../devices/soc0/amba/e0100000.sdhci/mmc_host/mmc0/mmc0:aaaa/
    --w------- 1 root root 4096 Mar 27 2023 uevent
    --w------- 1 root root 4096 Nov 9 00:38 unbind

    # ll /sys/devices/soc0/amba/e0101000.sdhci/mmc_host/mmc1
    total 0
    drwxr-xr-x 3 root root 0 Mar 27 2023 ./
    drwxr-xr-x 3 root root 0 Mar 27 2023 ../
    lrwxrwxrwx 1 root root 0 Nov 9 00:45 device -> ../../../e0101000.sdhci/
    drwxr-xr-x 2 root root 0 Nov 9 00:45 power/
    lrwxrwxrwx 1 root root 0 Mar 27 2023 subsystem -> ../../../../../../class/mmc_host/
    -rw-r--r-- 1 root root 4096 Mar 27 2023 uevent

    # ll /sys/bus/sdio/drivers/wl1271_sdio/
    total 0
    drwxr-xr-x 2 root root 0 Mar 27 2023 ./
    drwxr-xr-x 3 root root 0 Mar 27 2023 ../
    --w------- 1 root root 4096 Nov 9 00:40 bind
    --w------- 1 root root 4096 Mar 27 2023 uevent
    --w------- 1 root root 4096 Nov 9 00:40 unbind

    I instrumented some kernel code, specifically drivers/mmc/core/bus.c. Here's what booting on a functional device shows in syslog (ignore the time stamps):

     # grep mmc_bus /var/log/syslog
    Mar  2 12:58:11 localhost kernel: [    3.328975] mmc_bus_probe: card: type: SD(43690)
    Mar  2 12:58:11 localhost kernel: [    3.340514] mmc_bus_uevent: card: type: SD(43690)
    Mar  2 12:58:11 localhost kernel: [    3.466166] mmc_bus_uevent: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [    3.470789] mmc_bus_match: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [    3.475297] mmc_bus_probe: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [    7.875034] mmc_bus_uevent: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [    7.882550] mmc_bus_uevent: card: type: SD(43690)
    Mar  2 12:58:11 localhost kernel: [    8.173487] mmc_bus_uevent: card: type: SD(43690)
    Mar  2 12:58:11 localhost kernel: [    8.180265] mmc_bus_uevent: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [   10.388485] mmc_bus_uevent: card: type: SD(43690)
    Mar  2 12:58:11 localhost kernel: [   10.398074] mmc_bus_uevent: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [   10.658781] mmc_bus_uevent: card: type: SD(43690)
    Mar  2 12:58:11 localhost kernel: [   10.905161] mmc_bus_uevent: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [   10.910847] mmc_bus_uevent: card: type: SDIO(1)
    Mar  2 12:58:11 localhost kernel: [   11.824392] mmc_bus_uevent: card: type: SDIO(1)

    And here's what it looks like on the failed device:

    # grep mmc_bus /var/log/syslog
    Nov  8 23:42:07 MPM4-6001 kernel: [    2.765598] mmc_bus_uevent: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    2.771812] mmc_bus_match: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    2.818682] mmc_bus_probe: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    2.833311] mmc_bus_uevent: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    6.923134] mmc_bus_uevent: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    7.197601] mmc_bus_uevent: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    9.418848] mmc_bus_uevent: card: type: SD(43690)
    Nov  8 23:42:07 MPM4-6001 kernel: [    9.627947] mmc_bus_uevent: card: type: SD(43690)

    Apparently udev never raises an event for the second MMC bus. Presumably that's because the device acts like it's not there.

    -Nick

  • Hi Nick,

    Here I would suggest probing CMD and CLK and WL_EN on a logic analyzer if you are able. We need to understand the timing of all of this to see what is exactly is going on. The CMD plot you provided earlier suggests that the WL18x chip is not enabled at the same time.

  • Hi .

    That will be a bit of a challenge, but I'll give it a go.

    Thanks,

    -Nick

  • Hi .

    Okay, not quite what was asked for, but probably sufficient.

    I could only record two channels at a time - it's much easier to get two scope probes onto the proper test points than two or three logic analyzer grabbers.

    The first trace is WL_EN (yellow) and WL_CLK (red).

    The second trace is WL_EN (yellow) and WL_CMD (red).

    That's enough to show that WL_EN is high while other bus activity is ongoing.

    I've also tried probing WL_IRQ, and it is high continuously, even through the reboot process.

    Would WL_UART_DBG be of any use here?

    Thanks,

    -Nick

  • Would WL_UART_DBG be of any use here?

    Possibly. The UART line only outputs anything after FW completes and you have put the device into DBG mode.

    It would be good to probe the UART_DBG as a sanity check, but there shouldn't be anything on the line because the device's WL_EN has been toggled as should be in reset.

    I've also tried probing WL_IRQ, and it is high continuously,

    I'm a bit suspicious of this. I would imagine that on powerup this line is low, but I can't explain why this would be high even after setting WL_EN low. Do you feed this interrupt line directly into the SoC? Is there a buffer in between? Do you have an internal pullup enabled on the SoC?

  • Hi .

    I'll try to get a look at UART_DBG just in case.

    WL_IRQ is connected directly to the SoC. It has an external 10K pull-up to 1.8 V, no internal pulls. 

    Thanks,

    -Nick

  • OK, sounds good.

    Software wise, could you look at the unbind commands again? On my AM335x device, I can unbind and bind with the following commands, can you check in this drivers directory if you have something similar? 

    $ cd /sys/bus/platform/drivers/sdhci-omap

    $ echo 481d8000.mmc > unbind

    $ echo 481d8000.mmc > bind

  • Hi .

    Okay, I found /sys/bus/platform/drivers/sdhci-arasan:

    # ls -l
    total 0
    --w------- 1 root root 4096 Nov 10 21:25 bind
    lrwxrwxrwx 1 root root 0 Nov 10 21:20 e0100000.sdhci -> ../../../../devices/soc0/amba/e0100000.sdhci
    lrwxrwxrwx 1 root root 0 Nov 10 21:27 e0101000.sdhci -> ../../../../devices/soc0/amba/e0101000.sdhci
    --w------- 1 root root 4096 Mar 27 2023 uevent
    --w------- 1 root root 4096 Nov 10 21:25 unbind

    I tried unbind and bind:

    # echo e0101000.sdhci > unbind
    # echo e0101000.sdhci > bind

    Here's syslog's output in response to bind - the same as at boot:

    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680653] sdhci-arasan e0101000.sdhci: GPIO lookup for consumer cd
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680673] sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680717] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680753] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680777] sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680792] sdhci-arasan e0101000.sdhci: No GPIO consumer cd found
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680809] sdhci-arasan e0101000.sdhci: GPIO lookup for consumer wp
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680822] sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680856] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680889] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680910] sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.680924] sdhci-arasan e0101000.sdhci: No GPIO consumer wp found
    Nov 10 21:25:22 MPM4-6001 kernel: [11679.794888] mmc1: SDHCI controller on e0101000.sdhci [e0101000.sdhci] using ADMA

  • That's great that you could find this, now you should be able to debug without having to reboot each time.

    Sorry for not specifying, but could you try this on a working board? Does everything work OK?

  • Hi .

    Sorry for not thinking of that myself! :-)

    On a workingdevice, unbind shuts down wlcore and bind brings everything back up again - I'd say it's working correctly. That will definitely make testing easier!

    Thanks,

    -Nick

  • Hi .

    Unfortunately, I got a bit clumsy with my scope probes and accidentally caused the board to drop power momentarily. That reset the the WiLink8, which of course is now working properly. I'll have to wait for another failure. :-/

    It's now running this firmware:

    chip.fw_ver_str = Rev 8.9.0.0.90
    chip.phy_fw_ver_str = Rev 8.2.0.0.246

    If you can think of anything to look at before it fails, let me know.

    I'll be in touch...

    Thanks,

    -Nick

  • Hi Nick,

    Would it be possible for your to share a snippet of your schematic for the SoC and WL18x?

  • Hi .

    The schematic is open source. Here's a link to a PDF on GitHub: krtkl snickerdoodle

    I wasn't able to probe the DBG_UART signal before I fat-fingered the board, but is there anything useful to be learned by enabling its output? And if so, how do I go about doing that?

    Thanks,

    -Nick

  • Hi Nick,

    I see that you do have a pullup resistor in the WL_IRQ pin, so DBG_UART will print out stuff in normal operation. We have a public tool that is used to print out logs for firmware debugging purposes. The insight I was looking for is if the firmware is still running after WL_EN toggle. 

    On your DTS, could you remove "wlcore" and one of "1831" or "1837"? Also, I see the number "4" here, which interrupt type is it pointing to? I assume this is rising?

    wlcore: wlcore@0 {
            compatible = "wlcore", "ti,wl1831", "ti,wl1837";
            reg = <0x2>;
            interrupt-parent = <&gpio0>;
            interrupts = <0 4>;
        };

  • Hi .

    Here is my change:

    Interrupt type 4 is level-sensitive, active high. 

    wlcore: wlcore@0 {
        compatible = "ti,wl1837";
        reg = <0x2>;
        interrupt-parent = <&gpio0>;
        interrupts = <0 4>;
    };

    Here is lsmod before the change:

    # lsmod | grep wl | sort
    cfg80211 569344 3 wl18xx,wlcore,mac80211
    mac80211 622592 2 wl18xx,wlcore
    wl18xx 98304 0
    wlcore 212992 1 wl18xx
    wlcore_sdio 16384 0

     And after the change:

    # lsmod | grep wl | sort
    cfg80211 569344 3 wl18xx,wlcore,mac80211
    mac80211 622592 2 wl18xx,wlcore
    wl18xx 98304 0
    wlcore 212992 1 wl18xx
    wlcore_sdio 16384 0
    Where can I get the DBG_UART tool? Although I'll likely have to capture any output with the logic/protocol analyzer.
    Thanks,
    -Nick
  • Could you change the interrupt type to rising edge? I wonder if the interrupt was being missed and caused the initial issue. It doesn't explain why the IRQ stays high after WL_EN toggle, however. 

    These are the software debug tools:

    https://www.ti.com/lit/ug/swru435a/swru435a.pdf 

    https://www.ti.com/tool/WILINK-BT_WIFI-WIRELESS_TOOLS 

  • Hi .

    Okay, /proc/interrupts before:

    58: 942401 0 zynq-gpio 0 Level wl18xx

    and after:

    57: 237 0 zynq-gpio 0 Edge wl18xx

    "Before" is from a different device, hence the different IRQ number.

    Unfortunately, we're in the position of waiting for it to fail, so it will be difficult to claim things are working better simply because it hasn't failed yet. But we don't really have an better alternative at the moment.

    I'll have a look at the debug tools, and try to examine the output, if any, from the debug UART.

    Thanks,

    -Nick

  • Hi

    We're back in business, so to speak. This time I have two systems showing a WiFi failure. The original system, with the newer firmware and interrupt changes, and a second system that has the newer firmware, but the level-sensitive interrupt configuration.

    I've probed the DBG_UART pin both at rest and while executing 

    # cd /sys/bus/platform/drivers/sdhci-arasan
    # echo e0101000.sdhci > unbind
    # sleep 1
    # echo e0101000.sdhci > bind

    There was no activity on the pin. It stays low.

    I've included logs from both devices below. I've attempted to highlight the point of failure.

    Also, the settings in /sys/kernel/debug/mmc1/ios raised a question. In every case, including the working system, signal voltage was set to 3.3 V, although the actual signal voltage as observed with the oscilloscope is 1.8 V.

    Failed system before reboot:

    root@ARTEMIS16-3010:/sys/kernel/debug/mmc1# cat ios
    clock: 400000 Hz
    actual clock: 390624 Hz
    vdd: 7 (1.65 - 1.95 V)
    bus mode: 2 (push-pull)
    chip select: 0 (don't care)
    power mode: 2 (on)
    bus width: 0 (1 bits)
    timing spec: 0 (legacy)
    signal voltage: 0 (3.30 V)
    driver type: 0 (driver type B)

    Failed system after reboot:

    root@ARTEMIS16-3010:/sys/kernel/debug/mmc1# cat ios
    clock: 0 Hz
    vdd: 0 (invalid)
    bus mode: 2 (push-pull)
    chip select: 0 (don't care)
    power mode: 0 (off)
    bus width: 0 (1 bits)
    timing spec: 0 (legacy)
    signal voltage: 0 (3.30 V)
    driver type: 0 (driver type B)

    Working system:

    root@MPM4-6001:/sys/kernel/debug/mmc1# cat ios
    clock: 50000000 Hz
    actual clock: 49999999 Hz
    vdd: 7 (1.65 - 1.95 V)
    bus mode: 2 (push-pull)
    chip select: 0 (don't care)
    power mode: 2 (on)
    bus width: 2 (4 bits)
    timing spec: 2 (sd high-speed)
    signal voltage: 0 (3.30 V)
    driver type: 0 (driver type B)

    Thanks,

    -Nick

    Log from second device, ARTEMIS16-3010:

    At some point before I noticed the failure, /sys/kernel/debug/ieee80211/phy0 seems to have been replaced by /sys/kernel/debug/ieee80211/phy1.

    Nov 08 19:08:27 ARTEMIS16-3010 kernel: sched: RT throttling activated

    Nov 08 19:08:31 ARTEMIS16-3010 kernel: wlan0: deauthenticated from ac:ec:85:97:84:63 (Reason: 7=CLASS3_FRAME_FROM_NONASSOC_STA)
    Nov 08 19:08:32 ARTEMIS16-3010 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 08 19:08:32 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 08 19:08:32 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Lost carrier
    Nov 08 19:08:32 ARTEMIS16-3010 systemd-networkd[193]: wlan0: DHCP lease lost
    Nov 08 19:08:32 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for 192.168.4.104 on wlan0.
    Nov 08 19:08:32 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 08 19:08:34 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-DISCONNECTED bssid=ac:ec:85:97:84:63 reason=7
    Nov 08 19:08:34 ARTEMIS16-3010 avahi-daemon[433]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 08 19:08:34 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:08:34 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 08 19:08:36 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: SME: Trying to authenticate with ac:ec:85:97:84:63 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:08:38 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc.
    Nov 08 19:08:38 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:08:40 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 08 19:08:38 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc.
    Nov 08 19:08:40 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:08:38 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 08 19:08:38 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:08:41 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:08:41 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:08:41 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:08:42 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: send auth to c0:36:53:73:00:85 (try 1/3)
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: Trying to associate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: authenticated
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: associate with c0:36:53:73:00:85 (try 1/3)
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: RX AssocResp from c0:36:53:73:00:85 (capab=0x1111 status=0 aid=3)
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: associated
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: Associated with c0:36:53:73:00:85
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by c0:36:53:73:00:85
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: WPA: Key negotiation completed with c0:36:53:73:00:85 [PTK=CCMP GTK=CCMP]
    Nov 08 19:08:44 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:36:53:73:00:85 completed [id=0 id_str=]
    Nov 08 19:08:44 ARTEMIS16-3010 kernel: wlcore: Association completed.
    Nov 08 19:08:44 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Gained carrier
    Nov 08 19:08:44 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Connected WiFi access point: NixHouse (c0:36:53:73:00:85)
    Nov 08 19:08:44 ARTEMIS16-3010 systemd-networkd[193]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 08 19:08:44 ARTEMIS16-3010 systemd-networkd[193]: wlan0: DHCPv4 address 192.168.4.104/22 via 192.168.4.1
    Nov 08 19:08:44 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 08 19:08:44 ARTEMIS16-3010 avahi-daemon[433]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 08 19:08:44 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for 192.168.4.104 on wlan0.IPv4.
    Nov 08 19:08:45 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 08 19:08:45 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 08 19:08:45 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:08:45 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:08:45 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:09:01 ARTEMIS16-3010 CRON[9439]: pam_unix(cron:session): session opened for user root by (uid=0)
    Nov 08 19:09:01 ARTEMIS16-3010 CRON[9443]: (root) CMD ( [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
    Nov 08 19:09:01 ARTEMIS16-3010 CRON[9439]: pam_unix(cron:session): session closed for user root
    Nov 08 19:09:06 ARTEMIS16-3010 systemd[1]: Starting Clean php session files...
    Nov 08 19:09:07 ARTEMIS16-3010 systemd[1]: phpsessionclean.service: Succeeded.
    Nov 08 19:09:07 ARTEMIS16-3010 systemd[1]: Finished Clean php session files.
    Nov 08 19:17:01 ARTEMIS16-3010 CRON[9499]: pam_unix(cron:session): session opened for user root by (uid=0)
    Nov 08 19:17:01 ARTEMIS16-3010 CRON[9503]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Nov 08 19:17:01 ARTEMIS16-3010 CRON[9499]: pam_unix(cron:session): session closed for user root

    Nov 08 19:30:31 ARTEMIS16-3010 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 08 19:30:31 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 08 19:30:36 ARTEMIS16-3010 kernel: wlcore: Connection loss work (role_id: 0).
    Nov 08 19:30:36 ARTEMIS16-3010 kernel: wlan0: Connection to AP c0:36:53:73:00:85 lost
    Nov 08 19:30:36 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Lost carrier
    Nov 08 19:30:38 ARTEMIS16-3010 systemd-networkd[193]: wlan0: DHCP lease lost
    Nov 08 19:30:38 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for 192.168.4.104 on wlan0.
    Nov 08 19:30:38 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 08 19:30:39 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:36:53:73:00:85 reason=4 locally_generated=1
    Nov 08 19:30:38 ARTEMIS16-3010 avahi-daemon[433]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 08 19:30:38 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:30:38 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 08 19:30:39 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc.
    Nov 08 19:30:39 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 08 19:30:39 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:30:39 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc.
    Nov 08 19:30:39 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 08 19:30:39 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:30:42 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:30:43 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:30:43 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:30:43 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:30:43 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: SME: Trying to authenticate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: authenticate with b4:20:46:24:ad:25
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: send auth to b4:20:46:24:ad:25 (try 1/3)
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: Trying to associate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: authenticated
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: associate with b4:20:46:24:ad:25 (try 1/3)
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: RX AssocResp from b4:20:46:24:ad:25 (capab=0x1111 status=0 aid=2)
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: associated
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: Associated with b4:20:46:24:ad:25
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: WPA: Key negotiation completed with b4:20:46:24:ad:25 [PTK=CCMP GTK=CCMP]
    Nov 08 19:30:46 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-CONNECTED - Connection to b4:20:46:24:ad:25 completed [id=0 id_str=]
    Nov 08 19:30:46 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Gained carrier
    Nov 08 19:30:46 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Connected WiFi access point: NixHouse (b4:20:46:24:ad:25)
    Nov 08 19:30:46 ARTEMIS16-3010 systemd-networkd[193]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 08 19:30:46 ARTEMIS16-3010 kernel: wlcore: Association completed.
    Nov 08 19:30:48 ARTEMIS16-3010 kernel: wlcore: WARNING ELP wakeup timeout!
    Nov 08 19:30:48 ARTEMIS16-3010 kernel: wlcore: down
    Nov 08 19:30:48 ARTEMIS16-3010 kernel: wlcore: down
    Nov 08 19:30:48 ARTEMIS16-3010 kernel: ieee80211 phy0: Hardware restart was requested
    Nov 08 19:30:49 ARTEMIS16-3010 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 08 19:30:49 ARTEMIS16-3010 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 08 19:30:49 ARTEMIS16-3010 kernel: wlcore: Association completed.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:30:54 ARTEMIS16-3010 systemd-networkd[193]: wlan0: DHCPv4 address 192.168.4.104/22 via 192.168.4.1
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 08 19:30:54 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for 192.168.4.104 on wlan0.IPv4.

    Nov 08 19:39:50 ARTEMIS16-3010 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 08 19:39:50 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 08 19:39:50 ARTEMIS16-3010 systemd[1]: Starting Clean php session files...
    Nov 08 19:39:50 ARTEMIS16-3010 systemd[1]: Starting Ubuntu Advantage Timer for running repeated jobs...
    Nov 08 19:39:50 ARTEMIS16-3010 CRON[9517]: pam_unix(cron:session): session opened for user root by (uid=0)
    Nov 08 19:39:50 ARTEMIS16-3010 CRON[9526]: (root) CMD ( [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
    Nov 08 19:39:50 ARTEMIS16-3010 CRON[9517]: pam_unix(cron:session): session closed for user root
    Nov 08 19:39:51 ARTEMIS16-3010 systemd[1]: phpsessionclean.service: Succeeded.
    Nov 08 19:39:51 ARTEMIS16-3010 systemd[1]: Finished Clean php session files.
    Nov 08 19:39:52 ARTEMIS16-3010 systemd[1]: ua-timer.service: Succeeded.
    Nov 08 19:39:52 ARTEMIS16-3010 systemd[1]: Finished Ubuntu Advantage Timer for running repeated jobs.
    Nov 08 19:39:55 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Lost carrier
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for 192.168.4.104 on wlan0.
    Nov 08 19:39:55 ARTEMIS16-3010 kernel: wlan0: deauthenticated from b4:20:46:24:ad:25 (Reason: 7=CLASS3_FRAME_FROM_NONASSOC_STA)
    Nov 08 19:39:55 ARTEMIS16-3010 systemd-networkd[193]: wlan0: DHCP lease lost
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 08 19:39:55 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b4:20:46:24:ad:25 reason=7
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc.
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc.
    Nov 08 19:39:55 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: SME: Trying to authenticate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 08 19:39:55 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 08 19:39:55 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 08 19:39:55 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:39:55 ARTEMIS16-3010 kernel: wlan0: authenticate with b4:20:46:24:ad:25
    Nov 08 19:39:55 ARTEMIS16-3010 kernel: wlan0: send auth to b4:20:46:24:ad:25 (try 1/3)
    Nov 08 19:39:55 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: Trying to associate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 08 19:39:55 ARTEMIS16-3010 kernel: wlan0: authenticated
    Nov 08 19:39:55 ARTEMIS16-3010 kernel: wlan0: associate with b4:20:46:24:ad:25 (try 1/3)
    Nov 08 19:39:56 ARTEMIS16-3010 kernel: wlan0: RX AssocResp from b4:20:46:24:ad:25 (capab=0x1111 status=0 aid=2)
    Nov 08 19:39:56 ARTEMIS16-3010 kernel: wlan0: associated
    Nov 08 19:39:56 ARTEMIS16-3010 wpa_supplicant[304]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 08 19:39:56 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: Associated with b4:20:46:24:ad:25
    Nov 08 19:39:56 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 08 19:39:56 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 08 19:39:56 ARTEMIS16-3010 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 08 19:39:56 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: WPA: Key negotiation completed with b4:20:46:24:ad:25 [PTK=CCMP GTK=CCMP]
    Nov 08 19:39:56 ARTEMIS16-3010 wpa_supplicant[304]: wlan0: CTRL-EVENT-CONNECTED - Connection to b4:20:46:24:ad:25 completed [id=0 id_str=]
    Nov 08 19:39:56 ARTEMIS16-3010 systemd-networkd[193]: wlan0: Gained carrier
    Nov 08 19:39:56 ARTEMIS16-3010 kernel: wlcore: Association completed.
    Nov 08 19:39:57 ARTEMIS16-3010 avahi-daemon[433]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 08 19:39:57 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 08 19:39:57 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:39:57 ARTEMIS16-3010 avahi-daemon[433]: Withdrawing address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.
    Nov 08 19:39:57 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 08 19:40:00 ARTEMIS16-3010 systemd-networkd[193]: wlan0: DHCPv4 address 192.168.4.104/22 via 192.168.4.1
    Nov 08 19:40:00 ARTEMIS16-3010 avahi-daemon[433]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 08 19:40:00 ARTEMIS16-3010 avahi-daemon[433]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 08 19:40:00 ARTEMIS16-3010 avahi-daemon[433]: Registering new address record for 192.168.4.104 on wlan0.IPv4.
    Nov 08 19:40:01 ARTEMIS16-3010 kernel: wlcore: Hardware recovery in progress. FW ver: Rev 8.9.0.0.90
    Nov 08 19:40:01 ARTEMIS16-3010 kernel: wlcore: pc: 0x0, hint_sts: 0x00000020 count: 1
    Nov 08 19:40:01 ARTEMIS16-3010 kernel: wlcore: down
    Nov 08 19:40:01 ARTEMIS16-3010 kernel: wlcore: down
    Nov 08 19:40:01 ARTEMIS16-3010 kernel: ieee80211 phy0: Hardware restart was requested
    Nov 08 19:40:01 ARTEMIS16-3010 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 08 19:40:02 ARTEMIS16-3010 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 08 19:40:02 ARTEMIS16-3010 kernel: wlcore: Association completed.

    Nov 08 21:38:19 ARTEMIS16-3010 kernel: wlcore: WARNING no fw rx ba on tid 4

    Nov 10 21:45:43 ARTEMIS16-3010 kernel: wlcore: down
    Nov 10 21:45:43 ARTEMIS16-3010 kernel: wlan0: deauthenticating from c0:36:53:73:00:85 by local choice (Reason: 3=DEAUTH_LEAVING)
    Nov 10 21:45:43 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:36:53:73:00:85 reason=3 locally_generated=1
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Interface wlan0.IPv6 no longer relevant for mDNS.
    Nov 10 21:45:43 ARTEMIS16-3010 kernel: wlcore: down
    Nov 10 21:45:43 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Link DOWN
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 10 21:45:43 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for 192.168.4.104 on wlan0.
    Nov 10 21:45:44 ARTEMIS16-3010 systemd[1]: Starting Load/Save RF Kill Switch Status...
    Nov 10 21:45:44 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Lost carrier
    Nov 10 21:45:44 ARTEMIS16-3010 systemd-networkd[199]: wlan0: DHCP lease lost
    Nov 10 21:45:44 ARTEMIS16-3010 kernel: mmc1: card 0001 removed
    Nov 10 21:45:44 ARTEMIS16-3010 kernel: mmc_bus_uevent: card: type: SDIO(1)
    Nov 10 21:45:44 ARTEMIS16-3010 systemd[1]: Started Load/Save RF Kill Switch Status.
    Nov 10 21:45:44 ARTEMIS16-3010 wpa_supplicant[296]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
    Nov 10 21:45:44 ARTEMIS16-3010 wpa_supplicant[296]: Could not read interface p2p-dev-wlan0 flags: No such device

    Nov 10 21:45:49 ARTEMIS16-3010 systemd[1]: systemd-rfkill.service: Succeeded.
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: GPIO lookup for consumer cd
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: No GPIO consumer cd found
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: GPIO lookup for consumer wp
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/sdhci@e0101000[0]'
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: No GPIO consumer wp found
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc1: SDHCI controller on e0101000.sdhci [e0101000.sdhci] using ADMA
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdhci-arasan e0101000.sdhci: card claims to support voltages below defined range
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc1: new high speed SDIO card at address 0001
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc_bus_uevent: card: type: SDIO(1)
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc_bus_match: card: type: SDIO(1)
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc_bus_uevent: card: type: SDIO(1)
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc_bus_probe: card: type: SDIO(1)
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdio_bus_probe: func: 0xacb40000, drv: 0x7f195018
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: mmc_bus_uevent: card: type: SDIO(1)
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: sdio_bus_probe: func: 0xaca20000, drv: 0x7f195018
    Nov 10 21:45:49 ARTEMIS16-3010 kernel: wl18xx_driver wl18xx.0.auto: Direct firmware load for ti-connectivity/wl1271-nvs.bin failed with error -2
    Nov 10 21:45:50 ARTEMIS16-3010 kernel: mmc_bus_uevent: card: type: SDIO(1)
    Nov 10 21:45:50 ARTEMIS16-3010 kernel: mmc_bus_uevent: card: type: SDIO(1)
    Nov 10 21:45:50 ARTEMIS16-3010 kernel: wlcore: wl18xx HW: 183x or 180x, PG 2.2 (ROM 0x11)
    Nov 10 21:45:50 ARTEMIS16-3010 systemd[1]: Starting Load/Save RF Kill Switch Status...
    Nov 10 21:45:50 ARTEMIS16-3010 networkd-dispatcher[453]: WARNING:Unknown index 6 seen, reloading interface list
    Nov 10 21:45:50 ARTEMIS16-3010 systemd-udevd[9464]: Using default interface naming scheme 'v245'.
    Nov 10 21:45:50 ARTEMIS16-3010 kernel: wlcore: loaded
    Nov 10 21:45:50 ARTEMIS16-3010 systemd[1]: Started Load/Save RF Kill Switch Status.
    Nov 10 21:45:51 ARTEMIS16-3010 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 10 21:45:51 ARTEMIS16-3010 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 10 21:45:51 ARTEMIS16-3010 systemd-udevd[9464]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Nov 10 21:45:51 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Link UP
    Nov 10 21:45:51 ARTEMIS16-3010 systemd-networkd[199]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 10 21:45:51 ARTEMIS16-3010 systemd-networkd[199]: wlan0: IPv6 successfully enabled
    Nov 10 21:45:54 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: SME: Trying to authenticate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: authenticate with b4:20:46:24:ad:25
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: send auth to b4:20:46:24:ad:25 (try 1/3)
    Nov 10 21:45:54 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: Trying to associate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: authenticated
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: associate with b4:20:46:24:ad:25 (try 1/3)
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: RX AssocResp from b4:20:46:24:ad:25 (capab=0x1111 status=0 aid=3)
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: associated
    Nov 10 21:45:54 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: Associated with b4:20:46:24:ad:25
    Nov 10 21:45:54 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 10 21:45:54 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: WPA: Key negotiation completed with b4:20:46:24:ad:25 [PTK=CCMP GTK=CCMP]
    Nov 10 21:45:54 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: CTRL-EVENT-CONNECTED - Connection to b4:20:46:24:ad:25 completed [id=0 id_str=]
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlcore: Association completed.
    Nov 10 21:45:54 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Gained carrier
    Nov 10 21:45:54 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Connected WiFi access point: NixHouse (b4:20:46:24:ad:25)
    Nov 10 21:45:54 ARTEMIS16-3010 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 10 21:45:54 ARTEMIS16-3010 systemd-networkd[199]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 10 21:45:55 ARTEMIS16-3010 systemd[1]: systemd-rfkill.service: Succeeded.
    Nov 10 21:45:56 ARTEMIS16-3010 avahi-daemon[438]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 10 21:45:56 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Gained IPv6LL
    Nov 10 21:45:56 ARTEMIS16-3010 avahi-daemon[438]: New relevant interface wlan0.IPv6 for mDNS.
    Nov 10 21:45:56 ARTEMIS16-3010 avahi-daemon[438]: Registering new address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 10 21:45:57 ARTEMIS16-3010 avahi-daemon[438]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fe99:6ccc.
    Nov 10 21:45:57 ARTEMIS16-3010 avahi-daemon[438]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 10 21:45:57 ARTEMIS16-3010 avahi-daemon[438]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 10 21:45:57 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for fe80::3ea3:8ff:fe99:6ccc on wlan0.
    Nov 10 21:45:57 ARTEMIS16-3010 avahi-daemon[438]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.*.
    Nov 10 21:46:00 ARTEMIS16-3010 systemd-networkd[199]: wlan0: DHCPv4 address 192.168.4.104/22 via 192.168.4.1
    Nov 10 21:46:00 ARTEMIS16-3010 avahi-daemon[438]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 10 21:46:00 ARTEMIS16-3010 avahi-daemon[438]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 10 21:46:00 ARTEMIS16-3010 avahi-daemon[438]: Registering new address record for 192.168.4.104 on wlan0.IPv4.

    Nov 11 17:46:02 ARTEMIS16-3010 kernel: wlcore: WARNING no fw rx ba on tid 2

    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wl1271_sdio mmc1:0001:2: sdio write failed (-110)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlcore: WARNING Enable for recovery failed
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlcore: down
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlcore: down
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: ieee80211 phy1: Hardware restart was requested
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wl1271_sdio mmc1:0001:2: wl12xx_sdio_power_on: failed to get_sync(-110)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wl1271_sdio mmc1:0001:2: wl12xx_sdio_power_on: failed to get_sync(-22)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wl1271_sdio mmc1:0001:2: wl12xx_sdio_power_on: failed to get_sync(-22)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlcore: ERROR firmware boot failed despite 3 retries
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: deauthenticating from b4:20:46:24:ad:25 by local choice (Reason: 3=DEAUTH_LEAVING)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: HW problem - can not stop rx aggregation for b4:20:46:24:ad:25 tid 0
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: HW problem - can not stop rx aggregation for b4:20:46:24:ad:25 tid 6
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: HW problem - can not stop rx aggregation for b4:20:46:24:ad:25 tid 7
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: failed to remove key (0, b4:20:46:24:ad:25) from hardware (-5)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-5)
    Nov 15 04:01:04 ARTEMIS16-3010 kernel: wlan0: failed to remove key (2, ff:ff:ff:ff:ff:ff) from hardware (-5)
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Interface wlan0.IPv6 no longer relevant for mDNS.
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc.
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.104.
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fe99:6ccc on wlan0.
    Nov 15 04:01:04 ARTEMIS16-3010 avahi-daemon[438]: Withdrawing address record for 192.168.4.104 on wlan0.
    Nov 15 04:01:04 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b4:20:46:24:ad:25 reason=3 locally_generated=1
    Nov 15 04:01:04 ARTEMIS16-3010 wpa_supplicant[296]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 15 04:01:04 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Link DOWN
    Nov 15 04:01:04 ARTEMIS16-3010 systemd-networkd[199]: wlan0: Lost carrier
    Nov 15 04:01:04 ARTEMIS16-3010 systemd-networkd[199]: wlan0: DHCP lease lost

    Log from the original device, MPM4-6001:

    There are a number of errors like this: "MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13." I believe they were caused by making wl18xx-fw-4.bin readable only by root. It seems that eventually the firmware was read. I've since changed the file permissions to be readable by everyone.

    Nov 13 09:19:59 MPM4-6001 wpa_supplicant[240]: wlan0: WPA: Group rekeying completed with c0:36:53:73:00:85 [GTK=CCMP]
    Nov 13 21:27:39 MPM4-6001 sudo[11340]: snickerdoodle : TTY=pts/1 ; PWD=/home/snickerdoodle ; USER=root ; COMMAND=/usr/sbin/iw wlan0 scan
    Nov 13 21:27:54 MPM4-6001 sudo[11550]: snickerdoodle : TTY=pts/1 ; PWD=/home/snickerdoodle ; USER=root ; COMMAND=/usr/sbin/iw wlan0 scan
    Nov 13 21:33:15 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 13 21:33:15 MPM4-6001 wpa_supplicant[236]: Successfully initialized wpa_supplicant
    Nov 13 21:33:15 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 13 21:33:16 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 13 21:33:16 MPM4-6001 kernel: wlcore: ERROR firmware boot failed despite 3 retries
    Nov 13 21:33:16 MPM4-6001 systemd-networkd[191]: wlan0: Could not bring up interface: Permission denied
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 13 21:33:17 MPM4-6001 systemd-networkd[191]: wlan0: Link UP
    Nov 13 21:33:17 MPM4-6001 wpa_supplicant[277]: Successfully initialized wpa_supplicant
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: WARNING cmd set_template failed: -5
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: ERROR 2.4GHz PROBE request template failed
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: Hardware recovery in progress. FW ver: Rev 8.9.0.0.90
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: pc: 0x0, hint_sts: 0x00000020 count: 1
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: down
    Nov 13 21:33:17 MPM4-6001 kernel: wlcore: down
    Nov 13 21:33:17 MPM4-6001 kernel: ieee80211 phy0: Hardware restart was requested
    Nov 13 21:33:18 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 13 21:33:18 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 13 21:33:24 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 13 21:33:24 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 13 21:33:24 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 13 21:33:25 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 13 21:33:27 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5765 MHz)
    Nov 13 21:33:27 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 13 21:33:27 MPM4-6001 kernel: wlan0: send auth to c0:36:53:73:00:85 (try 1/3)
    Nov 13 21:33:27 MPM4-6001 kernel: wlan0: authenticated
    Nov 13 21:33:27 MPM4-6001 wpa_supplicant[236]: wlan0: Trying to associate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5765 MHz)
    Nov 13 21:33:27 MPM4-6001 kernel: wlan0: associate with c0:36:53:73:00:85 (try 1/3)
    Nov 13 21:33:27 MPM4-6001 kernel: wlan0: RX AssocResp from c0:36:53:73:00:85 (capab=0x1111 status=0 aid=1)
    Nov 13 21:33:27 MPM4-6001 kernel: wlan0: associated
    Nov 13 21:33:28 MPM4-6001 wpa_supplicant[236]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 13 21:33:28 MPM4-6001 wpa_supplicant[236]: wlan0: Associated with c0:36:53:73:00:85
    Nov 13 21:33:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 13 21:33:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 13 21:33:28 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by c0:36:53:73:00:85
    Nov 13 21:33:29 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Key negotiation completed with c0:36:53:73:00:85 [PTK=CCMP GTK=CCMP]
    Nov 13 21:33:29 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:36:53:73:00:85 completed [id=0 id_str=]
    Nov 13 21:33:29 MPM4-6001 systemd-networkd[191]: wlan0: Gained carrier
    Nov 13 21:33:29 MPM4-6001 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    Nov 13 21:33:29 MPM4-6001 kernel: wlcore: Association completed.
    Nov 13 21:33:29 MPM4-6001 systemd-networkd[191]: wlan0: Connected WiFi access point: NixHouse (c0:36:53:73:00:85)
    Nov 13 21:33:29 MPM4-6001 systemd-networkd[191]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 13 21:33:30 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 13 21:33:30 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv6 for mDNS.
    Nov 13 21:33:30 MPM4-6001 systemd-networkd[191]: wlan0: Gained IPv6LL
    Nov 13 21:33:30 MPM4-6001 avahi-daemon[257]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 13 21:33:32 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 13 21:33:32 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 13 21:33:32 MPM4-6001 avahi-daemon[257]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 13 21:33:32 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 13 21:33:32 MPM4-6001 avahi-daemon[257]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 13 21:33:34 MPM4-6001 systemd-networkd[191]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 13 21:33:34 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 13 21:33:34 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 13 21:33:34 MPM4-6001 avahi-daemon[257]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 14 04:24:32 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 7
    Nov 14 09:19:59 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Group rekeying completed with c0:36:53:73:00:85 [GTK=CCMP]
    Nov 14 19:56:03 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 14 19:56:03 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 14 19:56:05 MPM4-6001 systemd[1]: wpa_supplicant.service: Succeeded.
    Nov 14 19:56:05 MPM4-6001 systemd-networkd[191]: wlan0: DHCP lease lost
    Nov 14 19:56:25 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 14 19:56:25 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 14 19:56:25 MPM4-6001 kernel: wlcore: ERROR firmware boot failed despite 3 retries
    Nov 14 19:56:25 MPM4-6001 systemd-networkd[198]: wlan0: Could not bring up interface: Permission denied
    Nov 14 19:56:26 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 14 19:56:26 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 14 19:56:26 MPM4-6001 systemd-networkd[198]: wlan0: Link UP
    Nov 14 19:56:26 MPM4-6001 wpa_supplicant[276]: Successfully initialized wpa_supplicant
    Nov 14 19:56:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 14 19:56:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 14 19:56:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 14 19:56:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 14 19:56:29 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 14 19:56:29 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 14 19:56:31 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 14 19:56:31 MPM4-6001 kernel: wlan0: authenticate with b4:20:46:24:ad:25
    Nov 14 19:56:32 MPM4-6001 kernel: wlcore: WARNING CONFIGURE command NOK
    Nov 14 19:56:32 MPM4-6001 kernel: wlcore: WARNING Setting of rate policies failed: -5
    Nov 14 19:56:32 MPM4-6001 kernel: wlan0: failed to insert STA entry for the AP (error -16)
    Nov 14 19:56:32 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Authentication request to the driver failed
    Nov 14 19:56:32 MPM4-6001 kernel: wlcore: WARNING ELP wakeup timeout!
    Nov 14 19:56:32 MPM4-6001 kernel: wlcore: down
    Nov 14 19:56:32 MPM4-6001 kernel: wlcore: down
    Nov 14 19:56:32 MPM4-6001 kernel: ieee80211 phy0: Hardware restart was requested
    Nov 14 19:56:33 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 14 19:56:33 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5765 MHz)
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: send auth to c0:36:53:73:00:85 (try 1/3)
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: Trying to associate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5765 MHz)
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: authenticated
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: associate with c0:36:53:73:00:85 (try 1/3)
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: RX AssocResp from c0:36:53:73:00:85 (capab=0x1111 status=0 aid=1)
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: associated
    Nov 14 19:56:33 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by c0:36:53:73:00:85
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: Associated with c0:36:53:73:00:85
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Key negotiation completed with c0:36:53:73:00:85 [PTK=CCMP GTK=CCMP]
    Nov 14 19:56:33 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:36:53:73:00:85 completed [id=0 id_str=]
    Nov 14 19:56:33 MPM4-6001 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    Nov 14 19:56:33 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 14 19:56:33 MPM4-6001 kernel: wlcore: Association completed.
    Nov 14 19:56:33 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (c0:36:53:73:00:85)
    Nov 14 19:56:33 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 14 19:56:34 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 14 19:56:34 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 14 19:56:34 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 14 19:56:34 MPM4-6001 avahi-daemon[257]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 14 19:56:35 MPM4-6001 systemd-networkd[198]: wlan0: Gained IPv6LL
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv6 for mDNS.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 14 19:56:35 MPM4-6001 avahi-daemon[257]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 15 03:01:12 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 7
    Nov 15 09:19:59 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 6
    Nov 15 09:19:59 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Group rekeying completed with c0:36:53:73:00:85 [GTK=CCMP]
    Nov 16 09:19:59 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Group rekeying completed with c0:36:53:73:00:85 [GTK=CCMP]
    Nov 16 11:29:17 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 16 11:29:17 MPM4-6001 kernel: wlan0: deauthenticated from c0:36:53:73:00:85 (Reason: 3=DEAUTH_LEAVING)
    Nov 16 11:29:17 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 11:29:17 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:36:53:73:00:85 reason=3
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 16 11:29:17 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 16 11:29:17 MPM4-6001 avahi-daemon[257]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 11:29:18 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 11:29:18 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 11:29:18 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 11:29:18 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 11:29:18 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 11:29:18 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: authenticate with b4:20:46:24:ad:25
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: send auth to b4:20:46:24:ad:25 (try 1/3)
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: Trying to associate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5765 MHz)
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: authenticated
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: associate with b4:20:46:24:ad:25 (try 1/3)
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: RX AssocResp from b4:20:46:24:ad:25 (capab=0x1111 status=0 aid=1)
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: associated
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: Associated with b4:20:46:24:ad:25
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Key negotiation completed with b4:20:46:24:ad:25 [PTK=CCMP GTK=CCMP]
    Nov 16 11:29:21 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CONNECTED - Connection to b4:20:46:24:ad:25 completed [id=0 id_str=]
    Nov 16 11:29:21 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 16 11:29:21 MPM4-6001 kernel: wlcore: Association completed.
    Nov 16 11:29:21 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (b4:20:46:24:ad:25)
    Nov 16 11:29:21 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 16 11:29:21 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 16 11:29:21 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 16 11:29:21 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 11:29:21 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 16 11:29:21 MPM4-6001 avahi-daemon[257]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 16 11:29:22 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 16 11:29:22 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 11:29:22 MPM4-6001 avahi-daemon[257]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 11:29:22 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 11:29:22 MPM4-6001 avahi-daemon[257]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 11:30:22 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5320 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5320 cf2=0
    Nov 16 11:30:25 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5320 MHz, width 2 (5310/0 MHz)
    Nov 16 11:30:25 MPM4-6001 kernel: wlan0: Limiting TX power to 21 (24 - 3) dBm as advertised by b4:20:46:24:ad:25
    Nov 16 11:30:25 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5320 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5320 cf2=0
    Nov 16 11:30:25 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 16 11:30:28 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 16 11:30:28 MPM4-6001 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 16 11:30:33 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 16 11:30:33 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 16 11:30:33 MPM4-6001 kernel: wlcore: Connection loss work (role_id: 0).
    Nov 16 11:30:33 MPM4-6001 kernel: wlan0: Connection to AP b4:20:46:24:ad:25 lost
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 11:30:33 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b4:20:46:24:ad:25 reason=4 locally_generated=1
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 11:30:33 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 16 11:30:33 MPM4-6001 avahi-daemon[257]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 11:30:34 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with ac:ec:85:97:84:64 (SSID='NixHouse' freq=2437 MHz)
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: authenticate with ac:ec:85:97:84:64
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: send auth to ac:ec:85:97:84:64 (try 1/3)
    Nov 16 11:30:34 MPM4-6001 wpa_supplicant[236]: wlan0: Trying to associate with ac:ec:85:97:84:64 (SSID='NixHouse' freq=2437 MHz)
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: authenticated
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: associate with ac:ec:85:97:84:64 (try 1/3)
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: RX AssocResp from ac:ec:85:97:84:64 (capab=0x1431 status=0 aid=3)
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: associated
    Nov 16 11:30:34 MPM4-6001 wpa_supplicant[236]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 16 11:30:34 MPM4-6001 wpa_supplicant[236]: wlan0: Associated with ac:ec:85:97:84:64
    Nov 16 11:30:34 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 16 11:30:34 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 16 11:30:34 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by ac:ec:85:97:84:64
    Nov 16 11:30:35 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Key negotiation completed with ac:ec:85:97:84:64 [PTK=CCMP GTK=CCMP]
    Nov 16 11:30:35 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CONNECTED - Connection to ac:ec:85:97:84:64 completed [id=0 id_str=]
    Nov 16 11:30:35 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 16 11:30:35 MPM4-6001 kernel: wlcore: Association completed.
    Nov 16 11:30:35 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (ac:ec:85:97:84:64)
    Nov 16 11:30:35 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 16 11:30:35 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 11:30:35 MPM4-6001 avahi-daemon[257]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 11:35:29 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 kernel: wlan0: AP ac:ec:85:97:84:64 changed bandwidth, new config is 2437 MHz, width 2 (2427/0 MHz)
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 kernel: wlan0: AP ac:ec:85:97:84:64 changed bandwidth, new config is 2437 MHz, width 2 (2427/0 MHz)
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 kernel: wlan0: AP ac:ec:85:97:84:64 changed bandwidth, new config is 2437 MHz, width 2 (2427/0 MHz)
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 16 11:35:30w config is 2437 MHz, width 2 (2427/0 MHz)
    Nov 16 11:35:30 MPM4no fw rx ba on tid 4
    Nov 16 15:40:33 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 7
    Nov 16 22:26:18 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 22:26:18 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 22:26:20 MPM4-6001 systemd[1]: wpa_supplicant.service: Succeeded.
    Nov 16 22:26:20 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 16 22:26:39 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 16 22:26:39 MPM4-6001 wpa_supplicant[236]: Successfully initialized wpa_supplicant
    Nov 16 22:26:39 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 16 22:26:40 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 16 22:26:40 MPM4-6001 systemd-networkd[199]: wlan0: Could not bring up interface: Permission denied
    Nov 16 22:26:40 MPM4-6001 kernel: wlcore: ERROR firmware boot failed despite 3 retries
    Nov 16 22:26:40 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 16 22:26:41 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 16 22:26:41 MPM4-6001 systemd-networkd[199]: wlan0: Link UP
    Nov 16 22:26:41 MPM4-6001 wpa_supplicant[281]: Successfully initialized wpa_supplicant
    Nov 16 22:26:42 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 22:26:42 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 22:26:42 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 22:26:42 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 22:26:43 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 22:26:47 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5180 MHz)
    Nov 16 22:26:47 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 16 22:26:47 MPM4-6001 kernel: wlan0: send auth to c0:36:53:73:00:85 (try 1/3)
    Nov 16 22:26:49 MPM4-6001 kernel: wlan0: send auth to c0:36:53:73:00:85 (try 2/3)
    Nov 16 22:26:49 MPM4-6001 kernel: wlan0: authenticated
    Nov 16 22:26:49 MPM4-6001 wpa_supplicant[236]: wlan0: Trying to associate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5180 MHz)
    Nov 16 22:26:49 MPM4-6001 kernel: wlan0: associate with c0:36:53:73:00:85 (try 1/3)
    Nov 16 22:26:49 MPM4-6001 kernel: wlan0: RX AssocResp from c0:36:53:73:00:85 (capab=0x1111 status=0 aid=3)
    Nov 16 22:26:49 MPM4-6001 kernel: wlan0: associated
    Nov 16 22:26:49 MPM4-6001 wpa_supplicant[236]: wlan0: Associated with c0:36:53:73:00:85
    Nov 16 22:26:49 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 16 22:26:49 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 16 22:26:49 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by c0:36:53:73:00:85
    Nov 16 22:26:49 MPM4-6001 wpa_supplicant[236]: wlan0: WPA: Key negotiation completed with c0:36:53:73:00:85 [PTK=CCMP GTK=CCMP]
    Nov 16 22:26:49 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:36:53:73:00:85 completed [id=0 id_str=]
    Nov 16 22:26:49 MPM4-6001 systemd-networkd[199]: wlan0: Gained carrier
    Nov 16 22:26:50 MPM4-6001 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    Nov 16 22:26:49 MPM4-6001 systemd-networkd[199]: wlan0: Connected WiFi access point: NixHouse (c0:36:53:73:00:85)
    Nov 16 22:26:49 MPM4-6001 systemd-networkd[199]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 16 22:26:50 MPM4-6001 kernel: wlcore: Association completed.
    Nov 16 22:26:51 MPM4-6001 systemd-networkd[199]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 16 22:26:51 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 22:26:51 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 16 22:26:51 MPM4-6001 avahi-daemon[257]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 16 22:26:51 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 16 22:26:51 MPM4-6001 avahi-daemon[257]: New relevant interface wlan0.IPv6 for mDNS.
    Nov 16 22:26:51 MPM4-6001 systemd-networkd[199]: wlan0: Gained IPv6LL
    Nov 16 22:26:51 MPM4-6001 avahi-daemon[257]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 22:26:51 MPM4-6001 systemd-networkd-wait-online[237]: managing: wlan0
    Nov 16 22:26:53 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 16 22:26:53 MPM4-6001 avahi-daemon[257]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 22:26:53 MPM4-6001 avahi-daemon[257]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 22:26:53 MPM4-6001 avahi-daemon[257]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 16 22:26:53 MPM4-6001 avahi-daemon[257]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 16 22:26:53 MPM4-6001 systemd-networkd-wait-online[237]: managing: wlan0
    Nov 16 23:40:14 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 16 23:40:14 MPM4-6001 avahi-daemon[257]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 16 23:40:16 MPM4-6001 systemd[1]: wpa_supplicant.service: Succeeded.
    Nov 16 23:40:16 MPM4-6001 systemd-networkd[199]: wlan0: DHCP lease lost
    Nov 16 23:40:35 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 16 23:40:35 MPM4-6001 wpa_supplicant[238]: Successfully initialized wpa_supplicant
    Nov 16 23:40:35 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 16 23:40:36 MPM4-6001 kernel: wlcore: ERROR could not get firmware ti-connectivity/wl18xx-fw-4.bin: -13
    Nov 16 23:40:36 MPM4-6001 kernel: wlcore: ERROR firmware boot failed despite 3 retries
    Nov 16 23:40:36 MPM4-6001 systemd-networkd[198]: wlan0: Could not bring up interface: Permission denied
    Nov 16 23:40:36 MPM4-6001 wpa_supplicant[274]: Successfully initialized wpa_supplicant
    Nov 16 23:40:37 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 16 23:40:37 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Nov 16 23:40:37 MPM4-6001 systemd-networkd[198]: wlan0: Link UP
    Nov 16 23:40:38 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 23:40:38 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 23:40:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 23:40:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 23:40:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 16 23:40:43 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 16 23:40:43 MPM4-6001 wpa_supplicant[238]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5180 MHz)
    Nov 16 23:40:44 MPM4-6001 kernel: wlcore: WARNING ELP wakeup timeout!
    Nov 16 23:40:44 MPM4-6001 kernel: wlcore: down
    Nov 16 23:40:44 MPM4-6001 kernel: wlcore: down
    Nov 16 23:40:44 MPM4-6001 kernel: wlan0: failed to insert STA entry for the AP (error -16)
    Nov 16 23:40:44 MPM4-6001 kernel: ieee80211 phy0: Hardware restart was requested
    Nov 16 23:40:44 MPM4-6001 wpa_supplicant[238]: wlan0: SME: Authentication request to the driver failed
    Nov 16 23:40:44 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 16 23:40:44 MPM4-6001 kernel:e=UNKNOWN
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:86 (SSID='NixHouse' freq=2437 MHz)
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:86
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: send auth to c0:36:53:73:00:86 (try 1/3)
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: Trying to associate with c0:36:53:73:00:86 (SSID='NixHouse' freq=2437 MHz)
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: authenticated
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: associate with c0:36:53:73:00:86 (try 1/3)
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: RX AssocResp from c0:36:53:73:00:86 (capab=0x1431 status=0 aid=2)
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: associated
    Nov 17 11:42:00 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by c0:36:53:73:00:86
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: Associated with c0:36:53:73:00:86
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Key negotiation completed with c0:36:53:73:00:86 [PTK=CCMP GTK=CCMP]
    Nov 17 11:42:00 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:36:53:73:00:86 completed [id=0 id_str=]
    Nov 17 11:42:00 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 17 11:42:00 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (c0:36:53:73:00:86)
    Nov 17 11:42:00 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 17 11:42:00 MPM4-6001 kernel: wlcore: Association completed.
    Nov 17 11:42:01 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 17 11:42:01 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 17 11:42:01 MPM4-6001 avahi-daemon[253]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 17 11:42:01 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 17 11:42:01 MPM4-6001 avahi-daemon[253]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 17 11:42:06 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 17 11:42:06 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 17 11:42:06 MPM4-6001 avahi-daemon[253]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 17 11:42:06 MPM4-6001 avahi-daemon[253]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 17 12:47:44 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 7
    Nov 17 14:06:59 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 5
    Nov 18 09:19:59 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Group rekeying completed with c0:36:53:73:00:86 [GTK=CCMP]
    Nov 18 17:42:12 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 18 17:42:12 MPM4-6001 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 18 17:42:16 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 18 17:42:16 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 18 17:42:16 MPM4-6001 kernel: wlcore: Connection loss work (role_id: 0).
    Nov 18 17:42:16 MPM4-6001 kernel: wlan0: Connection to AP c0:36:53:73:00:86 lost
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 18 17:42:16 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:36:53:73:00:86 reason=4 locally_generated=1
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 18 17:42:16 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fec2:9407.
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fec2:9407.
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 18 17:42:16 MPM4-6001 avahi-daemon[253]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 18 17:42:17 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 18 17:42:18 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 18 17:42:18 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 18 17:42:18 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5180 MHz)
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: send auth to c0:36:53:73:00:85 (try 1/3)
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: Trying to associate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5180 MHz)
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: authenticated
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: associate with c0:36:53:73:00:85 (try 1/3)
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: RX AssocResp from c0:36:53:73:00:85 (capab=0x1111 status=0 aid=3)
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: associated
    Nov 18 17:42:21 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by c0:36:53:73:00:85
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: Associated with c0:36:53:73:00:85
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Key negotiation completed with c0:36:53:73:00:85 [PTK=CCMP GTK=CCMP]
    Nov 18 17:42:21 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:36:53:73:00:85 completed [id=0 id_str=]
    Nov 18 17:42:21 MPM4-6001 kernel: wlcore: Association completed.
    Nov 18 17:42:21 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 18 17:42:21 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (c0:36:53:73:00:85)
    Nov 18 17:42:21 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 18 17:42:21 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 18 17:42:21 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 18 17:42:21 MPM4-6001 avahi-daemon[253]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 18 17:42:21 MPM4-6001 avahi-daemon[253]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 18 17:42:22 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 18 17:42:22 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 18 17:42:22 MPM4-6001 avahi-daemon[253]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 18 17:42:22 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 18 17:42:22 MPM4-6001 avahi-daemon[253]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 19 11:09:31 MPM4-6001 kernel: wlan0: deauthenticated from c0:36:53:73:00:85 (Reason: 3=DEAUTH_LEAVING)
    Nov 19 11:09:31 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 19 11:09:31 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 19 11:09:31 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:36:53:73:00:85 reason=3
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fec2:9407.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fec2:9407.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 19 11:09:31 MPM4-6001 avahi-daemon[253]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 19 11:09:31 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 19 11:09:32 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 19 11:09:32 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 19 11:09:33 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 19 11:09:33 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 19 11:09:35 MPM4-6001 wpa_supplicant[238]: wlan0: SME: Trying to authenticate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5180 MHz)
    Nov 19 11:09:35 MPM4-6001 kernel: wlan0: authenticate with b4:20:46:24:ad:25
    Nov 19 11:09:35 MPM4-6001 kernel: wlan0: send auth to b4:20:46:24:ad:25 (try 1/3)
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: wlan0: Trying to associate with b4:20:46:24:ad:25 (SSID='NixHouse' freq=5180 MHz)
    Nov 19 11:09:36 MPM4-6001 kernel: wlan0: authenticated
    Nov 19 11:09:36 MPM4-6001 kernel: wlan0: associate with b4:20:46:24:ad:25 (try 1/3)
    Nov 19 11:09:36 MPM4-6001 kernel: wlan0: RX AssocResp from b4:20:46:24:ad:25 (capab=0x1111 status=0 aid=1)
    Nov 19 11:09:36 MPM4-6001 kernel: wlan0: associated
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: wlan0: Associated with b4:20:46:24:ad:25
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 19 11:09:36 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Key negotiation completed with b4:20:46:24:ad:25 [PTK=CCMP GTK=CCMP]
    Nov 19 11:09:36 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CONNECTED - Connection to b4:20:46:24:ad:25 completed [id=0 id_str=]
    Nov 19 11:09:36 MPM4-6001 kernel: wlcore: Association completed.
    Nov 19 11:09:36 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 19 11:09:36 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (b4:20:46:24:ad:25)
    Nov 19 11:09:36 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 19 11:09:36 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 19 11:09:36 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 19 11:09:36 MPM4-6001 avahi-daemon[253]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 19 11:09:36 MPM4-6001 avahi-daemon[253]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 19 11:09:37 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 19 11:09:37 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 19 11:09:37 MPM4-6001 avahi-daemon[253]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 19 11:09:37 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 19 11:09:37 MPM4-6001 avahi-daemon[253]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 19 11:10:37 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5620 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5620 cf2=0
    Nov 19 11:10:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-49 noise=9999 txrate=150000
    Nov 19 11:10:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5620 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5620 cf2=0
    Nov 19 11:10:39 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5620 MHz, width 2 (5630/0 MHz)
    Nov 19 11:10:39 MPM4-6001 kernel: wlan0: Limiting TX power to 21 (24 - 3) dBm as advertised by b4:20:46:24:ad:25
    Nov 19 11:10:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 19 11:10:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 19 11:10:42 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5180 MHz, width 2 (5190/0 MHz)
    Nov 19 11:10:42 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 19 12:05:58 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 6
    Nov 19 21:26:18 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 1
    Nov 20 01:15:10 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 3
    Nov 20 01:17:47 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 7
    Nov 20 01:31:31 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 5
    Nov 20 09:19:57 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Group rekeying completed with b4:20:46:24:ad:25 [GTK=CCMP]
    Nov 20 11:21:53 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5280 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5280 cf2=0
    Nov 20 11:21:56 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5280 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5280 cf2=0
    Nov 20 11:21:56 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5280 MHz, width 2 (5270/0 MHz)
    Nov 20 11:21:56 MPM4-6001 kernel: wlan0: Limiting TX power to 21 (24 - 3) dBm as advertised by b4:20:46:24:ad:25
    Nov 20 11:21:56 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 20 11:21:56 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 20 11:21:56 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5180 MHz, width 2 (5190/0 MHz)
    Nov 20 11:21:56 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 20 11:27:00 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5765 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5765 cf2=0
    Nov 20 11:27:05 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5765 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5765 cf2=0
    Nov 20 11:27:05 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5765 MHz, width 2 (5755/0 MHz)
    Nov 21 09:19:57 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Group rekeying completed with b4:20:46:24:ad:25 [GTK=CCMP]
    Nov 21 11:38:28 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5280 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5280 cf2=0
    Nov 21 11:38:30 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5280 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5280 cf2=0
    Nov 21 11:38:30 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5280 MHz, width 2 (5270/0 MHz)
    Nov 21 11:38:30 MPM4-6001 kernel: wlan0: Limiting TX power to 21 (24 - 3) dBm as advertised by b4:20:46:24:ad:25
    Nov 21 11:38:30 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 21 11:38:33 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 21 11:38:33 MPM4-6001 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 21 11:38:35 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5180 MHz, width 2 (5190/0 MHz)
    Nov 21 11:38:35 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:20:46:24:ad:25
    Nov 21 11:38:35 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 21 11:38:38 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 21 11:38:38 MPM4-6001 kernel: wlcore: Connection loss work (role_id: 0).
    Nov 21 11:38:38 MPM4-6001 kernel: wlan0: Connection to AP b4:20:46:24:ad:25 lost
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 21 11:38:38 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 21 11:38:38 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b4:20:46:24:ad:25 reason=4 locally_generated=1
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 21 11:38:38 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fec2:9407.
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2600:1700:e320:48df:3ea3:8ff:fec2:9407.
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 21 11:38:38 MPM4-6001 avahi-daemon[253]: Registering new address record for fe80::3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 21 11:38:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 11:38:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 11:38:39 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 11:38:40 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 11:38:40 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 11:38:42 MPM4-6001 wpa_supplicant[238]: wlan0: SME: Trying to authenticate with ac:ec:85:97:84:63 (SSID='NixHouse' freq=5180 MHz)
    Nov 21 11:38:42 MPM4-6001 kernel: wlan0: authenticate with ac:ec:85:97:84:63
    Nov 21 11:38:42 MPM4-6001 kernel: wlan0: send auth to ac:ec:85:97:84:63 (try 1/3)
    Nov 21 11:38:42 MPM4-6001 kernel: wlan0: authenticated
    Nov 21 11:38:42 MPM4-6001 wpa_supplicant[238]: wlan0: Trying to associate with ac:ec:85:97:84:63 (SSID='NixHouse' freq=5180 MHz)
    Nov 21 11:38:42 MPM4-6001 kernel: wlan0: associate with ac:ec:85:97:84:63 (try 1/3)
    Nov 21 11:38:42 MPM4-6001 kernel: wlan0: RX AssocResp from ac:ec:85:97:84:63 (capab=0x1111 status=0 aid=3)
    Nov 21 11:38:42 MPM4-6001 kernel: wlan0: associated
    Nov 21 11:38:43 MPM4-6001 wpa_supplicant[238]: nl80211: send_and_recv->nl_recvmsgs failed: -33
    Nov 21 11:38:43 MPM4-6001 wpa_supplicant[238]: wlan0: Associated with ac:ec:85:97:84:63
    Nov 21 11:38:43 MPM4-6001 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by ac:ec:85:97:84:63
    Nov 21 11:38:43 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
    Nov 21 11:38:43 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
    Nov 21 11:38:43 MPM4-6001 wpa_supplicant[238]: wlan0: WPA: Key negotiation completed with ac:ec:85:97:84:63 [PTK=CCMP GTK=CCMP]
    Nov 21 11:38:43 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CONNECTED - Connection to ac:ec:85:97:84:63 completed [id=0 id_str=]
    Nov 21 11:38:43 MPM4-6001 kernel: wlcore: Association completed.
    Nov 21 11:38:43 MPM4-6001 systemd-networkd[198]: wlan0: Gained carrier
    Nov 21 11:38:43 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (ac:ec:85:97:84:63)
    Nov 21 11:38:43 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 21 11:38:43 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 21 11:38:43 MPM4-6001 avahi-daemon[253]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 21 11:44:35 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5640 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5640 cf2=0
    Nov 21 11:44:38 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5640 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5640 cf2=0
    Nov 21 11:44:38 MPM4-6001 kernel: wlan0: AP ac:ec:85:97:84:63 changed bandwidth, new config is 5640 MHz, width 2 (5630/0 MHz)
    Nov 21 11:44:38 MPM4-6001 kernel: wlan0: Limiting TX power to 21 (24 - 3) dBm as advertised by ac:ec:85:97:84:63
    Nov 21 11:44:38 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5180 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5180 cf2=0
    Nov 21 11:44:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-BEACON-LOSS
    Nov 21 11:44:41 MPM4-6001 kernel: wlcore: Beacon loss detected. roles:0x1
    Nov 21 11:44:46 MPM4-6001 kernel: wlcore: Connection loss work (role_id: 0).
    Nov 21 11:44:46 MPM4-6001 kernel: wlan0: Connection to AP ac:ec:85:97:84:63 lost
    Nov 21 11:44:46 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 21 11:44:46 MPM4-6001 avahi-daemon[253]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 21 11:44:46 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 21 11:44:46 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 21 11:44:46 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-DISCONNECTED bssid=ac:ec:85:97:84:63 reason=4 locally_generated=1
    Nov 21 11:44:46 MPM4-6001 avahi-daemon[253]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 21 11:44:46 MPM4-6001 avahset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:41 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2447/0 MHz)
    Nov 21 11:49:42 MPM4-6001 wpa_supplicant[238]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=2437 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=2437 cf2=0
    Nov 21 11:49:42 MPM4-6001 kernel: wlan0: AP c0:36:53:73:00:86 changed bandwidth, new config is 2437 MHz, width 2 (2427/0 MHz)
    Nov 21 20:09:29 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 21 20:09:29 MPM4-6001 avahi-daemon[253]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 21 20:09:31 MPM4-6001 systemd[1]: wpa_supplicant.service: Succeeded.
    Nov 21 20:09:31 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 21 20:09:51 MPM4-6001 kernel: wlcore: PHY firmware version: Rev 8.2.0.0.246
    Nov 21 20:09:51 MPM4-6001 kernel: wlcore: firmware booted (Rev 8.9.0.0.90)
    Mar 27 17:54:13 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Mar 27 17:54:13 MPM4-6001 systemd-networkd[198]: wlan0: IPv6 successfully enabled
    Nov 21 20:09:51 MPM4-6001 wpa_supplicant[236]: Successfully initialized wpa_supplicant
    Mar 27 17:54:13 MPM4-6001 systemd[1]: Found device /sys/subsystem/net/devices/wlan0.
    Mar 27 17:54:13 MPM4-6001 systemd[1]: Started WPA supplicant for netplan wlan0.
    Nov 21 20:09:51 MPM4-6001 systemd-networkd[198]: wlan0: Link UP
    Nov 21 20:09:52 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 20:09:52 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 20:09:53 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 20:09:53 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 20:09:53 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
    Nov 21 20:09:53 MPM4-6001 wpa_supplicant[283]: Successfully initialized wpa_supplicant
    Nov 21 20:09:56 MPM4-6001 kernel: wlan0: authenticate with c0:36:53:73:00:85
    Nov 21 20:09:56 MPM4-6001 wpa_supplicant[236]: wlan0: SME: Trying to authenticate with c0:36:53:73:00:85 (SSID='NixHouse' freq=5180 MHz)
    Nov 21 20:09:56 MPM4-6001 kernel: wlan0: send d[198]: wlan0: Gained carrier
    Nov 22 11:55:07 MPM4-6001 systemd-networkd[198]: wlan0: Connected WiFi access point: NixHouse (b4:20:46:24:ad:25)
    Nov 22 11:55:07 MPM4-6001 systemd-networkd[198]: wlan0: found matching network '/run/systemd/network/10-netplan-wlan0.network', based on potentially unpredictable ifname
    Nov 22 11:55:07 MPM4-6001 systemd-networkd[198]: wlan0: DHCPv4 address 192.168.4.103/22 via 192.168.4.1
    Nov 22 11:55:07 MPM4-6001 avahi-daemon[260]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 22 11:55:07 MPM4-6001 avahi-daemon[260]: New relevant interface wlan0.IPv4 for mDNS.
    Nov 22 11:55:07 MPM4-6001 avahi-daemon[260]: Registering new address record for 192.168.4.103 on wlan0.IPv4.
    Nov 22 11:55:08 MPM4-6001 avahi-daemon[260]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::3ea3:8ff:fec2:9407.
    Nov 22 11:55:08 MPM4-6001 avahi-daemon[260]: Joining mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 22 11:55:08 MPM4-6001 avahi-daemon[260]: Registering new address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 22 11:55:08 MPM4-6001 avahi-daemon[260]: Withdrawing address record for fe80::3ea3:8ff:fec2:9407 on wlan0.
    Nov 22 11:55:08 MPM4-6001 avahi-daemon[260]: Registering new address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.*.
    Nov 22 11:56:00 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5640 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5640 cf2=0
    Nov 22 11:56:02 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-CHANNEL-SWITCH freq=5640 ht_enabled=1 ch_offset=0 ch_width=20 MHz cf1=5640 cf2=0
    Nov 22 11:56:02 MPM4-6001 kernel: wlan0: AP b4:20:46:24:ad:25 changed bandwidth, new config is 5640 MHz, width 2 (5630/0 MHz)
    Nov 22 11:56:02 MPM4-6001 kernel: wlan0: Limiting TX power to 21 (24 - 3) dBm as advertised by b4:20:46:24:ad:25
    Nov 22 12:44:37 MPM4-6001 kernel: wlcore: WARNING no fw rx ba on tid 4
    Nov 22 13:27:20 MPM4-6001 kernel: wlcore: WARNING Enable for recovery failed
    Nov 22 13:27:20 MPM4-6001 kernel: wlcore: down
    Nov 22 13:27:20 MPM4-6001 kernel: wlcore: down
    Nov 22 13:27:20 MPM4-6001 kernel: ieee80211 phy0: Hardware restart was requested
    Nov 22 13:27:20 MPM4-6001 kernel: wlcore: ERROR firmware boot failed despite 3 retries
    Nov 22 13:27:20 MPM4-6001 kernel: wlan0: deauthenticating from b4:20:46:24:ad:25 by local choice (Reason: 3=DEAUTH_LEAVING)
    Nov 22 13:27:20 MPM4-6001 kernel: wlan0: HW problem - can not stop rx aggregation for b4:20:46:24:ad:25 tid 0
    Nov 22 13:27:20 MPM4-6001 kernel: wlan0: HW problem - can not stop rx aggregation for b4:20:46:24:ad:25 tid 2
    Nov 22 13:27:20 MPM4-6001 kernel: wlan0: HW problem - can not stop rx aggregation for b4:20:46:24:ad:25 tid 6
    Nov 22 13:27:20 MPM4-6001 kernel: wlan0: failed to remove key (0, b4:20:46:24:ad:25) from hardware (-5)
    Nov 22 13:27:20 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b4:20:46:24:ad:25 reason=3 locally_generated=1
    Nov 22 13:27:20 MPM4-6001 kernel: wlan0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-5)
    Nov 22 13:27:20 MPM4-6001 systemd-networkd[198]: wlan0: Link DOWN
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Interface wlan0.IPv6 no longer relevant for mDNS.
    Nov 22 13:27:20 MPM4-6001 wpa_supplicant[236]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fd99:242a:99b6:1:3ea3:8ff:fec2:9407.
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Interface wlan0.IPv4 no longer relevant for mDNS.
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.103.
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Withdrawing address record for 2600:1700:e320:48df:3ea3:8ff:fec2:9407 on wlan0.
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Withdrawing address record for fd99:242a:99b6:1:3ea3:8ff:fec2:9407 on wlan0.
    Nov 22 13:27:20 MPM4-6001 avahi-daemon[260]: Withdrawing address record for 192.168.4.103 on wlan0.
    Nov 22 13:27:20 MPM4-6001 systemd-networkd[198]: wlan0: Lost carrier
    Nov 22 13:27:20 MPM4-6001 systemd-networkd[198]: wlan0: DHCP lease lost
    Nov 22 13:27:53 MPM4-6001 awdog[259]: NOTICE: [103:103]Watchdog::WiFiOkay()[Watchdog.cpp:197]:"WiFi status: error"
    Nov 22 13:27:58 MPM4-6001 systemd[1]: wpa_supplicant.service: Succeeded.
    Nov 22 13:28:32 MPM4-6001 wpa_supplicant[266]: Successfully initialized wpa_supplicant
    Nov 22 13:28:52 MPM4-6001 kernel: wlan-en-regulator: disabling
    Nov 22 13:29:54 MPM4-6001 systemd[1]: sys-subsystem-net-devices-wlan0.device: Job sys-subsystem-net-devices-wlan0.device/start timed out.
    Nov 22 13:29:54 MPM4-6001 systemd[1]: Timed out waiting for device /sys/subsystem/net/devices/wlan0.
    Nov 22 13:29:54 MPM4-6001 systemd[1]: Dependency failed for WPA supplicant for netplan wlan0.
    Nov 22 13:29:54 MPM4-6001 systemd[1]: netplan-wpa-wlan0.service: Job netplan-wpa-wlan0.service/start failed with result 'dependency'.
    Nov 22 13:29:54 MPM4-6001 systemd[1]: sys-subsystem-net-devices-wlan0.device: Job sys-subsystem-net-devices-wlan0.device/start failed with result 'timeout'.

  • Hi Nick,

    I'll review your logs and get back to you next week due to the thanksgiving holidays. However, were there any printouts during these commands?

    # echo e0101000.sdhci > unbind
    # sleep 1
    # echo e0101000.sdhci > bind
  • And just to confirm, the unbind / bind commands operate fine on working units?

  • Hi .

    No output from the commands, but this in syslog:

    Nov 22 21:31:02 localhost kernel: [1199301.057440] sdhci-arasan e0101000.sdhci: GPIO lookup for consumer cd
    Nov 22 21:31:02 localhost kernel: [1199301.057460] sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    Nov 22 21:31:02 localhost kernel: [1199301.057505] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/amba/sdhci@e0101000[0]'
    Nov 22 21:31:02 localhost kernel: [1199301.057541] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/amba/sdhci@e0101000[0]'
    Nov 22 21:31:02 localhost kernel: [1199301.057564] sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    Nov 22 21:31:02 localhost kernel: [1199301.057579] sdhci-arasan e0101000.sdhci: No GPIO consumer cd found
    Nov 22 21:31:02 localhost kernel: [1199301.057595] sdhci-arasan e0101000.sdhci: GPIO lookup for consumer wp
    Nov 22 21:31:02 localhost kernel: [1199301.057608] sdhci-arasan e0101000.sdhci: using device tree for GPIO lookup
    Nov 22 21:31:02 localhost kernel: [1199301.057642] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/amba/sdhci@e0101000[0]'
    Nov 22 21:31:02 localhost kernel: [1199301.057676] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/amba/sdhci@e0101000[0]'
    Nov 22 21:31:02 localhost kernel: [1199301.057697] sdhci-arasan e0101000.sdhci: using lookup tables for GPIO lookup
    Nov 22 21:31:02 localhost kernel: [1199301.057711] sdhci-arasan e0101000.sdhci: No GPIO consumer wp found
    Nov 22 21:31:02 localhost kernel: [1199301.170194] mmc1: SDHCI controller on e0101000.sdhci [e0101000.sdhci] using ADMA

    Thanks, and have a great holiday.

    -Nick

  • They appear to. This is from a device that isn't using WiFi at the moment:

    root@MUGS8-2002:/sys/bus/platform/drivers/sdhci-arasan# ip link show wlan0
    6: wlan0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 90:70:65:01:2c:cf brd ff:ff:ff:ff:ff:ff

    root@MUGS8-2002:/sys/bus/platform/drivers/sdhci-arasan# echo e0101000.sdhci > unbind

    root@MUGS8-2002:/sys/bus/platform/drivers/sdhci-arasan# ip link show wlan0
    Device "wlan0" does not exist.

    root@MUGS8-2002:/sys/bus/platform/drivers/sdhci-arasan# echo e0101000.sdhci > bind

    root@MUGS8-2002:/sys/bus/platform/drivers/sdhci-arasan# ip link show wlan0
    7: wlan0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 90:70:65:01:2c:cf brd ff:ff:ff:ff:ff:ff

  • Hi Nick,

    Looking through the logs, the issue I see is that for some reason your Zynq host loses communication with the WL18xMOD. A toggling of the enable pin will clear the RAM of the WL18x and allow for another reupload of firmware. Immediately after WL_EN toggle, the sdhci driver should probe the SDIO device (ie. WL18x) and then load the wlcore driver. However, this is not happening and we should investigate why.

    However, I understand that this issue occurs only when there is a crash on the WL18x driver, and the unbind/bind command works on non-crashed Wi-Fi boards. On the chance there is a bug in the WL18x driver, could you update one of your boards to a newer kernel? Atleast 5.10?

  • Hi .

    I copied the contents of the drivers/net/wireless/ti directory from Xilinx's "xlnx_rebase_v5.15_LTS_2022.1_update" branch and rebuilt the kernel. There was no change in behavior. 

    Is the mismatched voltage as shown in /sys/kernel/debug/mmc1/ios not an issue, then?

    root@MPM4-6001:/sys/kernel/debug/mmc1# cat ios
    clock: 50000000 Hz
    actual clock: 49999999 Hz
    vdd: 7 (1.65 - 1.95 V)
    bus mode: 2 (push-pull)
    chip select: 0 (don't care)
    power mode: 2 (on)
    bus width: 2 (4 bits)
    timing spec: 2 (sd high-speed)
    signal voltage: 0 (3.30 V)
    driver type: 0 (driver type B)

    Thanks,

    -Nick

  • Hi Nick,

    Yes the signal voltage level does not matter. The wlcore driver does not detect it nor change its behavior. That value is determined by the lower level MMC driver.

  • Hi .

    We may have had a miscommunication earlier when talking about WL_UART_DBG. I was referring to pin 42, described in the datasheet as "Option: WLAN logger." I've only just realized that there is another UART function, WL_RS232_TX/RX available on GPIO 1 and 2 (pins 27 and 26). I have not probed the TX pin - I'm currently waiting to hear from the SBC manufacturer regarding the location of the relevant test points.

    The data sheet only barely acknowledges its existence, and then only to say it is "for debug only." Is there any documentation that describes the use of this communication channel? 

    Thanks

    -Nick

  • Unfortunately, the test points are on the back side of the SBC, and not easily accessible. I might be able to solder leads to the test points, but that will require depowering the device and waiting for it to fail again. 

    The UART signals are routed to the SBC's "platform controller" MCU. Another option, would be to try to handle the communication there, although there's not a convenient communication channel to the MCU from Linux.

    So the first thing is to determine if it's worth the effort to try and communicate with the WiLink via the UART interface.

  • Hey Nick, 

    I would not recommend going through the processing of hooking into the WL_RS232 lines. These lines are for connecting to a host PC where the user can run a tool called "RTTT": https://www.ti.com/lit/ug/swau085f/swau085f.pdf 

    It is a tool for calibration and RF debug. It would not be related to the activity you are trying to debug with your linux processor that communicates over SDIO. 

    I would actually be interested in to see if the device responds to any mmc probe. You shared this photo earlier: /cfs-file/__key/communityserver-discussions-components-files/968/pastedimage1699564007248v2.png If you have a logic analyzer, could you zoom into the CMD and CLK signals on a boot? It would be helpful to understand if the device is responding at all, because right now it looks like it is just powered off completely. 

  • Hi

    I've managed to capture WL_SDIO_CLK and WL_SDIO_CMD in the logic analyzer. I've got a 1.1 MB .csv file (reduced from 558 MB) that no one wants me to post here.

    What is it I'm looking for? The total capture is about seven seconds. There are two portions where CLK is active, one about 26 ms long and the other about 21 ms long. The gap between them is about 95 ms.

    The first starts with about 15 ms of 400 kHz clocks before the first activity on CMD. The second is similar, with about 12.5 ms of clocks before any CMD activity.

    How can I tell if the chip is responding? Won't I also need to look at WL_SDIO_D0?

    Thanks,

    -Nick

  • Hi NIck,

    From the capture we need to understand if the device is responding at all. So the host MMC driver will send values like CMD0 and CMD8, and the WL8 should be responding to these. If the WL8 is responding, then there is an issue on the host MMC driver. 

  • Hi 

    (Edited to include the correct bit streams).

    That much I understand. My question is regarding how to recognize a response from the chip as opposed to a command from the driver. Will the chip respond on WL_SDIO_CMD, or on WL_SDIO_D0?

    Here is the activity on WL_SDIO_CMD. There are many 1s before, between, and after these two excerpted sections.

    11001111110011000000000000000000000000000000000000000000001111000000000000000000000000111111000011111

    11001111110011000000000000000000000000000000000000000000001111000000000000000000000000111111000011111

    Thanks,

    -Nick

  • Hi

    I think those bit patterns are still wrong - they show each bit twice. If I look at CMD only after CLK transitions from low to high, I get this bit pattern:

    11111111 011101000000000000000000000011000000000000111001 11111111

    That at least gets start and stop bits in the correct positions, and the frame could be parsed as CMD52:

    0 - start
    1 - tx

    110100 - index (CMD52, IO_RW_DIRECT)

    0 - r/w (is 0 a read?)
    000 - function 0
    0 - raw flag
    0 - stuff
    00000000000000110 - register address (6)
    0 - stuff
    00000000 - write data

    0011100 - crc
    1 - stop

    If that's correct, then the second bit pattern is:

    0 - start
    1 - tx

    110100 - CMD52

    1 - r/w (1 must mean write)
    000 - function 0
    0 - raw flag
    0 - stuff
    00000000000000110 register address (6)
    0 - stuff
    00001000 - write data

    1001111 - crc
    1 - stop

    drivers/net/wireless/ti/wlcore/sdio.c defines 

    static struct wl1271_if_operations sdio_ops = {
        .read = wl12xx_sdio_raw_read,
        .write = wl12xx_sdio_raw_write,
        .power = wl12xx_sdio_set_power,
        .set_block_size = wl1271_sdio_set_block_size,
    };

    and wl12xx_sdio_raw_write uses CMD52, so this potentially makes sense.

    There doesn't appear to be any response from the chip in either case, though.

    I found some SDIO documentation that describes CMD52, write 0x6 = 0x8 is a reset command.

    -Nick

  • Hi Nick,

    I agree the part does not seem to be responding. This makes me think that the 32khz slow clock is not working on device re-enable. This is a necessary component per the timing diagram in the datasheet:

    So I've looked further into this section on your schematic, and I'm a bit confused. It seems to me that the Slow CLK is fed by a crystal and this crystal drives the WiLink and the Zynq SOC. Could there possibly be an issue with that clock circuitry? Does the crystal's enable pin ever change state?  

    I am thinking the crystal was disabled temporarily causing some timing issue and that's why it requires a power cycle. While looking into that, as a debug item, could you split the crystal from the Zynq SOC and feed in an external crystal, and then run a multi-day test to see if the issue re-occurs? 

    I would also imagine that since the crystal also feeds the Zynq that the Zynq would also have issues, but it doesn't sound like it. 

  • Hi .

    The 32 KHz oscillator only feeds the WiLink and the STM32 MCU. And the STM32 doesn't actually use it for anything in its current configuration. I've asked the manufacturer to identify the location of TP123. If it's accessible from the front side of the board, I'll stick a scope probe on it and see if there's a signal.

    That hypothesis is consistent with the observed behavior - rebooting the device only affects the ARM processor(s), not the STM32 MCU, whereas removing power obviously affects everything.

    Thanks,

    -Nick

  • Hi .

    Unfortunately, everything is on the back side of the board and not readily accessible. I'll probably have to power off the device to do anything more, which means waiting for another failure. I'll let you know when I have more to report.

    Thanks,

    -Nick

  • Hi

    I have news, and some questions.

    I modified the STM32 platform controller's firmware to allow me to change the state of the GPIO pins at runtime. One of the pins is the "enable" input to the 32 KHz oscillator. This allowed me to disable and re-enable it at will. 

    I found that disabling the oscillator (at least, deasserting the GPIO pin that controls its enable input) sometimes caused the WiLink8 to fail, but not always. If it didn't fail, I could make it fail by leaving the oscillator disabled and using unbind/bind to try to reset the WiFi side of the chip. That would eventually cause the chip to fail, producing a state that at least appeared to be the same as the unprovoked failures we've been looking at. 

    Even after re-enabling the 32 KHZ oscillator, unbind/bind would not recover the chip; however...

    If I set the GPIO output controlling the BT_EN input to 0, I could then recover WiFi functionality with unbind/bind. As mentioned, I have not yet had the chance to try this on a device that has failed on its own, but it does raise the question about the role of BT_EN in all of this.

    Is this expected behavior? Is it expected that BE_EN must be deasserted before WIFI_EN can be used to reload the chip firmware?

    We're not using BT at all, so there's no need for BT_EN to be asserted.

    Does any of this shed light on what's happening?

    Thanks,

    -Nick