quad sata hat issue

quad_sata_hat_issue

Hello there,
I am using the QUAD SATA HAT (v1.2). I updated the JMicron firmware to v8.1.3.6 on all 4 ports.
I use the script to make OMV detect the disks' names and manufacturers. That's all good.
I have a RAID10 array, and works flawlessly.

However, when a power failure occurs (something which happens more often that I'd like in my area and my old house), pretty much every time, the PI only detects 2 disks upon that first boot after the power cut. I have to manually SSH into the PI and issue a reboot (normally one, sometimes more) to make the Pi detect all 4 drives.

Here's what it looks after the power failure:
```
    # lsblk 
    NAME        MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
    sda           8:0    0  1.8T  0 disk 
    └─sda1        8:1    0  1.8T  0 part 
    sdb           8:16   0  1.8T  0 disk 
    └─sdb1        8:17   0  1.8T  0 part 
    mmcblk0     179:0    0 29.7G  0 disk 
    ├─mmcblk0p1 179:1    0  256M  0 part /boot
    └─mmcblk0p2 179:2    0 29.5G  0 part /
```

The rockpi service looks good:
```
  # systemctl status rockpi-sata.service 
    ● rockpi-sata.service - Rockpi SATA Hat
       Loaded: loaded (/lib/systemd/system/rockpi-sata.service; enabled; vendor preset: enabled)
       Active: active (running) since Sun 2021-11-21 07:17:07 GMT; 50min ago
     Main PID: 767 (python3)
        Tasks: 6 (limit: 4915)
       CGroup: /system.slice/rockpi-sata.service
               ├─ 767 /usr/bin/python3 /usr/bin/rockpi-sata/main.py on
               ├─1489 /usr/bin/python3 /usr/bin/rockpi-sata/main.py on
               ├─1490 /usr/bin/python3 /usr/bin/rockpi-sata/main.py on
               ├─1491 /usr/bin/python3 /usr/bin/rockpi-sata/main.py on
               └─1492 /usr/bin/python3 /usr/bin/rockpi-sata/main.py on

    Nov 21 07:17:07 pinas systemd[1]: Started Rockpi SATA Hat.
```

And dmesg doesn't show anything special:
```
    # dmesg
    [    0.000000] Booting Linux on physical CPU 0x0
    [    0.000000] Linux version 5.10.63-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1459 SMP Wed Oct 6 16:41:57 BST 2021
    [    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
    [    0.000000] CPU: div instructions available: patching division code
    [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
    [    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.4
    [    0.000000] random: fast init done
    [    0.000000] Memory policy: Data cache writealloc
    [    0.000000] Reserved memory: created CMA memory pool at 0x000000001ac00000, size 320 MiB
    [    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
    [    0.000000] Zone ranges:
    [    0.000000]   DMA      [mem 0x0000000000000000-0x000000002fffffff]
    [    0.000000]   Normal   empty
    [    0.000000]   HighMem  [mem 0x0000000030000000-0x00000001ffffffff]
    [    0.000000] Movable zone start for each node
    [    0.000000] Early memory node ranges
    [    0.000000]   node   0: [mem 0x0000000000000000-0x000000003e5fffff]
    [    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]
    [    0.000000]   node   0: [mem 0x0000000100000000-0x00000001ffffffff]
    [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff]
    [    0.000000] On node 0 totalpages: 2074112
    [    0.000000]   DMA zone: 1728 pages used for memmap
    [    0.000000]   DMA zone: 0 pages reserved
    [    0.000000]   DMA zone: 196608 pages, LIFO batch:63
    [    0.000000]   HighMem zone: 1877504 pages, LIFO batch:63
    [    0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920
    [    0.000000] pcpu-alloc: s50828 r8192 d22900 u81920 alloc=20*4096
    [    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
    [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 2072384
    [    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1  smsc95xx.macaddr=DC:A6:32:F1:5F:1C vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  console=ttyS0,115200 console=tty1 root=PARTUUID=9e80988c-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
    [    0.000000] Kernel parameter elevator= does not have any effect anymore.
                   Please use sysfs to set IO scheduler for individual devices.
    [    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
    [    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
    [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
    [    0.000000] software IO TLB: mapped [mem 0x0000000012400000-0x0000000016400000] (64MB)
    [    0.000000] Memory: 7809304K/8296448K available (10240K kernel code, 1364K rwdata, 3192K rodata, 2048K init, 891K bss, 159464K reserved, 327680K cma-reserved, 7510016K highmem)
    [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
    [    0.000000] ftrace: allocating 34315 entries in 68 pages
    [    0.000000] ftrace: allocated 68 pages with 2 groups
    [    0.000000] rcu: Hierarchical RCU implementation.
    [    0.000000] 	Rude variant of Tasks RCU enabled.
    [    0.000000] 	Tracing variant of Tasks RCU enabled.
    [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
    [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
    [    0.000000] GIC: Using split EOI/Deactivate mode
    [    0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1
    [    0.000008] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
    [    0.000035] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
    [    0.000098] bcm2835: system timer (irq = 25)
    [    0.000748] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
    [    0.000770] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
    [    0.000793] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
    [    0.000810] Switching to timer-based delay loop, resolution 18ns
    [    0.001068] Console: colour dummy device 80x30
    [    0.001843] printk: console [tty1] enabled
    [    0.001909] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
    [    0.001963] pid_max: default: 32768 minimum: 301
    [    0.002141] LSM: Security Framework initializing
    [    0.002342] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
    [    0.002387] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
    [    0.003872] cgroup: Disabling memory control group subsystem
    [    0.004122] CPU: Testing write buffer coherency: ok
    [    0.004595] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
    [    0.005819] Setting up static identity map for 0x200000 - 0x20003c
    [    0.006035] rcu: Hierarchical SRCU implementation.
    [    0.006976] smp: Bringing up secondary CPUs ...
    [    0.008188] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
    [    0.009548] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
    [    0.010926] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
    [    0.011086] smp: Brought up 1 node, 4 CPUs
    [    0.011133] SMP: Total of 4 processors activated (432.00 BogoMIPS).
    [    0.011163] CPU: All CPU(s) started in HYP mode.
    [    0.011190] CPU: Virtualization extensions available.
    [    0.012061] devtmpfs: initialized
    [    0.026192] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
    [    0.026451] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [    0.026505] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
    [    0.034719] pinctrl core: initialized pinctrl subsystem
    [    0.035814] NET: Registered protocol family 16
    [    0.039713] DMA: preallocated 1024 KiB pool for atomic coherent allocations
    [    0.040496] audit: initializing netlink subsys (disabled)
    [    0.040769] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1
    [    0.041365] thermal_sys: Registered thermal governor 'step_wise'
    [    0.042056] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
    [    0.042112] hw-breakpoint: maximum watchpoint size is 8 bytes.
    [    0.042528] Serial: AMBA PL011 UART driver
    [    0.077349] bcm2835-mbox fe00b880.mailbox: mailbox enabled
    [    0.090894] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-10-29T10:47:49, variant start_cd
    [    0.100908] raspberrypi-firmware soc:firmware: Firmware hash is b8a114e5a9877e91ca8f26d1a5ce904b2ad3cf13
    [    0.142089] Kprobes globally optimized
    [    0.147357] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
    [    0.151599] vgaarb: loaded
    [    0.152084] SCSI subsystem initialized
    [    0.152327] usbcore: registered new interface driver usbfs
    [    0.152416] usbcore: registered new interface driver hub
    [    0.152503] usbcore: registered new device driver usb
    [    0.152871] usb_phy_generic phy: supply vcc not found, using dummy regulator
    [    0.154768] clocksource: Switched to clocksource arch_sys_counter
    [    1.113706] VFS: Disk quotas dquot_6.6.0
    [    1.113825] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
    [    1.114004] FS-Cache: Loaded
    [    1.114223] CacheFiles: Loaded
    [    1.125095] NET: Registered protocol family 2
    [    1.125366] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
    [    1.126646] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
    [    1.126807] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
    [    1.126892] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
    [    1.126981] TCP: Hash tables configured (established 8192 bind 8192)
    [    1.127156] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
    [    1.127211] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
    [    1.127496] NET: Registered protocol family 1
    [    1.128223] RPC: Registered named UNIX socket transport module.
    [    1.128257] RPC: Registered udp transport module.
    [    1.128285] RPC: Registered tcp transport module.
    [    1.128313] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [    1.128351] PCI: CLS 0 bytes, default 64
    [    1.131315] Initialise system trusted keyrings
    [    1.131563] workingset: timestamp_bits=14 max_order=21 bucket_order=7
    [    1.139906] zbud: loaded
    [    1.142077] FS-Cache: Netfs 'nfs' registered for caching
    [    1.142851] NFS: Registering the id_resolver key type
    [    1.142917] Key type id_resolver registered
    [    1.142946] Key type id_legacy registered
    [    1.143107] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
    [    1.143141] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
    [    1.144239] Key type asymmetric registered
    [    1.144271] Asymmetric key parser 'x509' registered
    [    1.144478] bounce: pool size: 64 pages
    [    1.144534] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
    [    1.144804] io scheduler mq-deadline registered
    [    1.144836] io scheduler kyber registered
    [    1.149309] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
    [    1.149361] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
    [    1.149462] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000
    [    1.149571] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000
    [    1.206873] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
    [    1.207272] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
    [    1.207309] pci_bus 0000:00: root bus resource [bus 00-ff]
    [    1.207344] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
    [    1.207456] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
    [    1.207714] pci 0000:00:00.0: PME# supported from D0 D3hot
    [    1.211195] PCI: bus0: Fast back to back transfers disabled
    [    1.211550] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
    [    1.211694] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
    [    1.212145] pci 0000:01:00.0: PME# supported from D0 D3hot
    [    1.215630] PCI: bus1: Fast back to back transfers disabled
    [    1.215722] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
    [    1.215764] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
    [    1.215865] pci 0000:00:00.0: PCI bridge to [bus 01]
    [    1.215904] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
    [    1.216328] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
    [    1.216573] pcieport 0000:00:00.0: PME: Signaling with IRQ 64
    [    1.225371] iproc-rng200 fe104000.rng: hwrng registered
    [    1.225698] vc-mem: phys_addr:0x00000000 mem_base=0x3f000000 mem_size:0x3f600000(1014 MiB)
    [    1.226614] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
    [    1.238870] brd: module loaded
    [    1.251201] loop: module loaded
    [    1.252990] Loading iSCSI transport class v2.0-870.
    [    1.256254] libphy: Fixed MDIO Bus: probed
    [    1.257990] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
    [    1.274803] libphy: bcmgenet MII bus: probed
    [    1.364919] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
    [    1.366103] usbcore: registered new interface driver r8152
    [    1.366190] usbcore: registered new interface driver lan78xx
    [    1.366279] usbcore: registered new interface driver smsc95xx
    [    1.414119] xhci_hcd 0000:01:00.0: xHCI Host Controller
    [    1.414172] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
    [    1.417444] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000060000000890
    [    1.418801] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
    [    1.418843] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    1.418879] usb usb1: Product: xHCI Host Controller
    [    1.418909] usb usb1: Manufacturer: Linux 5.10.63-v7l+ xhci-hcd
    [    1.418940] usb usb1: SerialNumber: 0000:01:00.0
    [    1.419684] hub 1-0:1.0: USB hub found
    [    1.419799] hub 1-0:1.0: 1 port detected
    [    1.420486] xhci_hcd 0000:01:00.0: xHCI Host Controller
    [    1.420529] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
    [    1.420575] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
    [    1.421106] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
    [    1.421146] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    1.421182] usb usb2: Product: xHCI Host Controller
    [    1.421211] usb usb2: Manufacturer: Linux 5.10.63-v7l+ xhci-hcd
    [    1.421241] usb usb2: SerialNumber: 0000:01:00.0
    [    1.421975] hub 2-0:1.0: USB hub found
    [    1.422063] hub 2-0:1.0: 4 ports detected
    [    1.423775] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
    [    1.424112] dwc_otg: FIQ enabled
    [    1.424128] dwc_otg: NAK holdoff enabled
    [    1.424142] dwc_otg: FIQ split-transaction FSM enabled
    [    1.424160] Module dwc_common_port init
    [    1.424629] usbcore: registered new interface driver uas
    [    1.424792] usbcore: registered new interface driver usb-storage
    [    1.425012] mousedev: PS/2 mouse device common for all mice
    [    1.426699] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
    [    1.431171] sdhci: Secure Digital Host Controller Interface driver
    [    1.431204] sdhci: Copyright(c) Pierre Ossman
    [    1.431945] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
    [    1.432570] sdhci-pltfm: SDHCI platform and OF driver helper
    [    1.436762] ledtrig-cpu: registered to indicate activity on CPUs
    [    1.437129] hid: raw HID events driver (C) Jiri Kosina
    [    1.437345] usbcore: registered new interface driver usbhid
    [    1.437375] usbhid: USB HID core driver
    [    1.443161] Initializing XFRM netlink socket
    [    1.443225] NET: Registered protocol family 17
    [    1.443361] Key type dns_resolver registered
    [    1.443730] Registering SWP/SWPB emulation handler
    [    1.443932] registered taskstats version 1
    [    1.443978] Loading compiled-in X.509 certificates
    [    1.445993] Key type ._fscrypt registered
    [    1.446025] Key type .fscrypt registered
    [    1.446053] Key type fscrypt-provisioning registered
    [    1.457586] uart-pl011 fe201000.serial: there is not valid maps for state default
    [    1.457913] uart-pl011 fe201000.serial: cts_event_workaround enabled
    [    1.458006] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2
    [    1.464707] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
    [    1.465815] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
    [    1.465849] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
    [    1.496211] of_cfs_init
    [    1.496379] of_cfs_init: OK
    [    1.518806] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
    [    1.520514] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
    [    1.522218] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
    [    1.525266] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
    [    1.526988] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
    [    1.534996] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
    [    1.535673] Waiting for root device PARTUUID=9e80988c-02...
    [    1.610268] mmc1: new high speed SDIO card at address 0001
    [    1.642818] mmc0: new ultra high speed DDR50 SDHC card at address aaaa
    [    1.643719] mmcblk0: mmc0:aaaa SE32G 29.7 GiB
    [    1.645703]  mmcblk0: p1 p2
    [    1.663668] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
    [    1.663714] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
    [    1.704816] usb 1-1: new high-speed USB device number 2 using xhci_hcd
    [    1.887472] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
    [    1.887520] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
    [    1.887554] usb 1-1: Product: USB2.0 Hub
    [    1.889527] hub 1-1:1.0: USB hub found
    [    1.889858] hub 1-1:1.0: 4 ports detected
    [    1.922933] EXT4-fs (mmcblk0p2): recovery complete
    [    1.924370] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
    [    1.924483] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
    [    1.929520] devtmpfs: mounted
    [    1.939450] Freeing unused kernel memory: 2048K
    [    1.939786] Run /sbin/init as init process
    [    1.939815]   with arguments:
    [    1.939829]     /sbin/init
    [    1.939843]   with environment:
    [    1.939858]     HOME=/
    [    1.939872]     TERM=linux
    [    2.315157] systemd[1]: System time before build time, advancing clock.
    [    2.425068] NET: Registered protocol family 10
    [    2.426488] Segment Routing with IPv6
    [    2.496521] systemd[1]: systemd 241 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)
    [    2.498117] systemd[1]: Detected architecture arm.
    [    2.547454] systemd[1]: Set hostname to <pinas>.
    [    2.951344] random: lvmconfig: uninitialized urandom read (4 bytes read)
    [    3.467227] systemd[1]: /lib/systemd/system/smbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/smbd.pid → /run/samba/smbd.pid; please update the unit file accordingly.
    [    3.504695] systemd[1]: /lib/systemd/system/nmbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/nmbd.pid → /run/samba/nmbd.pid; please update the unit file accordingly.
    [    3.579654] systemd[1]: /lib/systemd/system/rpc-statd.service:13: PIDFile= references path below legacy directory /var/run/, updating /var/run/rpc.statd.pid → /run/rpc.statd.pid; please update the unit file accordingly.
    [    3.648116] random: systemd: uninitialized urandom read (16 bytes read)
    [    3.667241] random: systemd: uninitialized urandom read (16 bytes read)
    [    3.667893] systemd[1]: Listening on Network Service Netlink Socket.
    [    3.668953] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
    [    3.672617] systemd[1]: Created slice system-systemd\x2dfsck.slice.
    [    3.674220] systemd[1]: Created slice system-getty.slice.
    [    3.801058] i2c /dev entries driver
    [    4.057032] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
    [    4.406194] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
    [    4.528668] systemd-journald[151]: Received request to flush runtime journal from PID 1
    [    5.031254] Driver for 1-wire Dallas network protocol.
    [    5.033972] gpio-4 (onewire@0): enforced open drain please flag it properly in DT/ACPI DSDT/board file
    [    5.052201] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
    [    5.055566] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
    [    5.058885] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
    [    5.064748] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
    [    5.102121] mc: Linux media interface: v0.10
    [    5.116887] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.119139] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
    [    5.119164] [vc_sm_connected_init]: start
    [    5.129584] vc_sm_cma_vchi_init: failed to open VCHI service (-1)
    [    5.129604] [vc_sm_connected_init]: failed to initialize shared memory service
    [    5.139107] videodev: Linux video capture interface: v2.00
    [    5.175209] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.175246] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.183046] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.187828] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.191440] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.195856] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
    [    5.221970] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
    [    5.260227] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
    [    5.286596] bcm2835_audio bcm2835_audio: card created with 8 channels
    [    5.287792] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
    [    5.380399] cfg80211: Loading compiled-in X.509 certificates for regulatory database
    [    5.474152] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0
    [    5.506826] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
    [    5.676653] brcmfmac: F1 signature read @0x18000000=0x15264345
    [    5.682070] [drm] No displays found. Consider forcing hotplug if HDMI is attached
    [    5.682226] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
    [    5.682910] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 1
    [    5.745098] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
    [    5.746738] usbcore: registered new interface driver brcmfmac
    [    6.039611] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
    [    6.039737] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
    [    6.051435] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan  4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e
    [    8.190689] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
    [    8.191265] bcmgenet fd580000.ethernet eth0: Link is Down
    [    9.953152] uart-pl011 fe201000.serial: no DMA platform data
    [    9.965115] 8021q: 802.1Q VLAN Support v1.8
    [   10.335006] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
    [   10.391159] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
    [   11.934816] random: crng init done
    [   11.934839] random: 7 urandom warning(s) missed due to ratelimiting
    [   14.815256] usb 2-2: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
    [   14.856755] usb 2-2: New USB device found, idVendor=1058, idProduct=0a10, bcdDevice=81.36
    [   14.856778] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=5
    [   14.856796] usb 2-2: Product: JMS56x Series
    [   14.856814] usb 2-2: Manufacturer: JMicron
    [   14.856830] usb 2-2: SerialNumber: 1234567890123
    [   14.884008] scsi host0: uas
    [   14.885883] scsi 0:0:0:0: Direct-Access     Samsung  SSD 850 EVO 2TB  8136 PQ: 0 ANSI: 6
    [   14.889178] scsi 0:0:0:1: Direct-Access     CT2000BX 500SSD1          8136 PQ: 0 ANSI: 6
    [   14.889390] sd 0:0:0:0: [sda] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
    [   14.889716] sd 0:0:0:0: [sda] Write Protect is off
    [   14.889737] sd 0:0:0:0: [sda] Mode Sense: 67 00 10 08
    [   14.890294] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
    [   14.891173] sd 0:0:0:0: [sda] Optimal transfer size 33553920 bytes
    [   14.892534] sd 0:0:0:1: [sdb] 3907029168 512-byte logical blocks: (2.00 TB/1.82 TiB)
    [   14.892829] sd 0:0:0:1: [sdb] Write Protect is off
    [   14.892851] sd 0:0:0:1: [sdb] Mode Sense: 67 00 10 08
    [   14.893931] sd 0:0:0:1: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA
    [   14.894861] sd 0:0:0:1: [sdb] Optimal transfer size 33553920 bytes
    [   14.938797]  sda: sda1
    [   14.945012] sd 0:0:0:0: [sda] Attached SCSI disk
    [   14.958670]  sdb: sdb1
    [   14.962562] sd 0:0:0:1: [sdb] Attached SCSI disk
    [   15.006080] sd 0:0:0:0: Attached scsi generic sg0 type 0
    [   15.006326] sd 0:0:0:1: Attached scsi generic sg1 type 0
    [   16.892287] Bluetooth: Core ver 2.22
    [   16.892397] NET: Registered protocol family 31
    [   16.892414] Bluetooth: HCI device and connection manager initialized
    [   16.892445] Bluetooth: HCI socket layer initialized
    [   16.892468] Bluetooth: L2CAP socket layer initialized
    [   16.892504] Bluetooth: SCO socket layer initialized
    [   16.904978] Bluetooth: HCI UART driver ver 2.3
    [   16.905002] Bluetooth: HCI UART protocol H4 registered
    [   16.905111] Bluetooth: HCI UART protocol Three-wire (H5) registered
    [   16.907841] Bluetooth: HCI UART protocol Broadcom registered
    [   17.268328] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
    [   17.268348] Bluetooth: BNEP filters: protocol multicast
    [   17.268377] Bluetooth: BNEP socket layer initialized
    [   26.875177] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
    [   26.875241] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    [   39.324990] NFSD: Using UMH upcall client tracking operations.
    [   39.325015] NFSD: starting 90-second grace period (net f0000089)
    [   52.840351] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.eth0.retrans_time - use net.ipv6.neigh.eth0.retrans_time_ms instead
    [   58.051126] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
    [   58.051149] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
    [   89.916172] usb 2-1: new SuperSpeed Gen 1 USB device number 3 using xhci_hcd
    [   89.957434] usb 2-1: New USB device found, idVendor=152d, idProduct=0561, bcdDevice= 0.01
    [   89.957458] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=5
    [   89.957476] usb 2-1: Product: JMS56x Series
    [   89.957494] usb 2-1: Manufacturer: JMicron
    [   89.957511] usb 2-1: SerialNumber: RANDOM__A879645F5DA5
    [   89.968506] usb-storage 2-1:1.0: USB Mass Storage device detected
    [   89.969479] scsi host1: usb-storage 2-1:1.0
```

It is possible that the tockpi service starts *before* the USB devices are initialised. Or some other race condition...

Any help, is appreciated, thank you!