Sep 22 15:18:18 rolyspi2 fake-hwclock[118]: Fri 22 Sep 05:18:14 UTC 2023 Sep 22 15:18:18 rolyspi2 systemd[1]: Started File System Check on Root Device. Sep 22 15:18:18 rolyspi2 systemd-fsck[139]: e2fsck 1.44.5 (15-Dec-2018) Sep 22 15:18:18 rolyspi2 systemd-fsck[139]: rootfs: clean, 193950/1933312 files, 2082576/7725184 blocks Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Remount Root and Kernel File Systems... Sep 22 15:18:18 rolyspi2 systemd[1]: Started Set the console keyboard layout. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Remount Root and Kernel File Systems. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Load/Save Random Seed... Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Booting Linux on physical CPU 0x0 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Linux version 5.10.103-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) #1529 SMP Tue Mar 8 12:24:00 GMT 2022 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] CPU: div instructions available: patching division code Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.4 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] random: fast init done Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Memory policy: Data cache writealloc Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Reserved memory: created CMA memory pool at 0x000000001ac00000, size 320 MiB Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Zone ranges: Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] DMA [mem 0x0000000000000000-0x000000002fffffff] Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Normal empty Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] HighMem [mem 0x0000000030000000-0x00000001ffffffff] Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Movable zone start for each node Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Early memory node ranges Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] node 0: [mem 0x0000000000000000-0x000000002fffffff] Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] node 0: [mem 0x0000000100000000-0x00000001ffffffff] Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] On node 0 totalpages: 2015232 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] DMA zone: 1728 pages used for memmap Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] DMA zone: 0 pages reserved Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] DMA zone: 196608 pages, LIFO batch:63 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] HighMem zone: 1818624 pages, LIFO batch:63 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] pcpu-alloc: s50828 r8192 d22900 u81920 alloc=20*4096 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2013504 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60D,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 smsc95xx.macaddr=DC:A6:32:E0:C8:43 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=tty1 root=PARTUUID=389d8ea4-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Kernel parameter elevator= does not have any effect anymore. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Please use sysfs to set IO scheduler for individual devices. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] software IO TLB: mapped [mem 0x0000000012400000-0x0000000016400000] (64MB) Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Memory: 7575876K/8060928K available (10240K kernel code, 1366K rwdata, 3196K rodata, 2048K init, 882K bss, 157372K reserved, 327680K cma-reserved, 7274496K highmem) Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] ftrace: allocating 34355 entries in 101 pages Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] ftrace: allocated 101 pages with 4 groups Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] rcu: Hierarchical RCU implementation. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Rude variant of Tasks RCU enabled. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] Tracing variant of Tasks RCU enabled. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Flush Journal to Persistent Storage... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Create System Users... Sep 22 15:18:18 rolyspi2 systemd[1]: Started udev Coldplug all Devices. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Sep 22 15:18:18 rolyspi2 systemd[1]: Started Load/Save Random Seed. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Flush Journal to Persistent Storage. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Create System Users. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Create Static Device Nodes in /dev... Sep 22 15:18:18 rolyspi2 systemd[1]: Started Create Static Device Nodes in /dev. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting udev Kernel Device Manager... Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Local File Systems (Pre). Sep 22 15:18:18 rolyspi2 systemd[1]: Started udev Kernel Device Manager. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Show Plymouth Boot Screen... Sep 22 15:18:18 rolyspi2 systemd[1]: Received SIGRTMIN+20 from PID 170 (plymouthd). Sep 22 15:18:18 rolyspi2 systemd[1]: Started Show Plymouth Boot Screen. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Local Encrypted Volumes. Sep 22 15:18:18 rolyspi2 systemd-udevd[198]: Using default interface naming scheme 'v240'. Sep 22 15:18:18 rolyspi2 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4" Sep 22 15:18:18 rolyspi2 systemd[1]: Found device /dev/disk/by-partuuid/389d8ea4-01. Sep 22 15:18:18 rolyspi2 mtp-probe: checking bus 1, device 3: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1" Sep 22 15:18:18 rolyspi2 mtp-probe: bus: 1, device: 3 was not an MTP device Sep 22 15:18:18 rolyspi2 mtp-probe: checking bus 1, device 4: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3" Sep 22 15:18:18 rolyspi2 mtp-probe: bus: 1, device: 4 was not an MTP device Sep 22 15:18:18 rolyspi2 mtp-probe: bus: 1, device: 5 was not an MTP device Sep 22 15:18:18 rolyspi2 systemd[1]: Starting File System Check on /dev/disk/by-partuuid/389d8ea4-01... Sep 22 15:18:18 rolyspi2 systemd-udevd[171]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:18:18 rolyspi2 systemd-udevd[183]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:18:18 rolyspi2 systemd-udevd[180]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:18:18 rolyspi2 systemd-udevd[198]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:18:18 rolyspi2 systemd-udevd[159]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:18:18 rolyspi2 systemd-fsck[305]: fsck.fat 4.1 (2017-01-24) Sep 22 15:18:18 rolyspi2 systemd-fsck[305]: /dev/mmcblk0p1: 292 files, 98800/516190 clusters Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 22 15:18:18 rolyspi2 systemd-udevd[195]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in FUSE Control File System being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Started File System Check on /dev/disk/by-partuuid/389d8ea4-01. Sep 22 15:18:18 rolyspi2 systemd[1]: Mounting /boot... Sep 22 15:18:18 rolyspi2 systemd[1]: Mounted /boot. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Local File Systems. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Preprocess NFS configuration... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Set console font and keymap... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Create Volatile Files and Directories... Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Sep 22 15:18:18 rolyspi2 systemd[1]: nfs-config.service: Succeeded. Sep 22 15:18:18 rolyspi2 systemd-udevd[163]: Using default interface naming scheme 'v240'. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Preprocess NFS configuration. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Set console font and keymap. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Load/Save RF Kill Switch Status... Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target NFS client services. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Remote File Systems (Pre). Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Remote File Systems. Sep 22 15:18:18 rolyspi2 systemd-udevd[193]: Using default interface naming scheme 'v240'. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Load/Save RF Kill Switch Status. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Create Volatile Files and Directories. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Network Time Synchronization... Sep 22 15:18:18 rolyspi2 systemd[1]: Started Update UTMP about System Boot/Shutdown. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Network Time Synchronization. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target System Time Synchronized. Sep 22 15:18:18 rolyspi2 systemd[1]: Received SIGRTMIN+20 from PID 170 (plymouthd). Sep 22 15:18:18 rolyspi2 systemd[1]: plymouth-read-write.service: Succeeded. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target System Initialization. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Daily man-db regeneration. Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on D-Bus System Message Bus Socket. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Daily rotation of log files. Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on GPS (Global Positioning System) Daemon Sockets. Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on signalk.socket. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Daily apt download activities. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Daily apt upgrade and clean activities. Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on CUPS Scheduler. Sep 22 15:18:18 rolyspi2 systemd[1]: Started CUPS Scheduler. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Paths. Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Sep 22 15:18:18 rolyspi2 systemd[1]: Listening on triggerhappy.socket. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Sockets. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Basic System. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] GIC: Using split EOI/Deactivate mode Sep 22 15:18:18 rolyspi2 kernel: [ 0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1 Sep 22 15:18:18 rolyspi2 kernel: [ 0.000007] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns Sep 22 15:18:18 rolyspi2 kernel: [ 0.000026] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns Sep 22 15:18:18 rolyspi2 kernel: [ 0.000085] bcm2835: system timer (irq = 25) Sep 22 15:18:18 rolyspi2 systemd[1]: Started openplotter-network.service. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000740] arch_timer: cp15 timer(s) running at 54.00MHz (phys). Sep 22 15:18:18 rolyspi2 kernel: [ 0.000758] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Sep 22 15:18:18 rolyspi2 systemd[1]: Started signalk.service. Sep 22 15:18:18 rolyspi2 kernel: [ 0.000777] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Sep 22 15:18:18 rolyspi2 kernel: [ 0.000791] Switching to timer-based delay loop, resolution 18ns Sep 22 15:18:18 rolyspi2 kernel: [ 0.001043] Console: colour dummy device 80x30 Sep 22 15:18:18 rolyspi2 kernel: [ 0.001113] printk: console [tty1] enabled Sep 22 15:18:18 rolyspi2 systemd[1]: Started openplotter-can-read.service. Sep 22 15:18:18 rolyspi2 kernel: [ 0.001169] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) Sep 22 15:18:18 rolyspi2 kernel: [ 0.001201] pid_max: default: 32768 minimum: 301 Sep 22 15:18:18 rolyspi2 kernel: [ 0.001366] LSM: Security Framework initializing Sep 22 15:18:18 rolyspi2 kernel: [ 0.001550] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Sep 22 15:18:18 rolyspi2 systemd[1]: Started CUPS Scheduler. Sep 22 15:18:18 rolyspi2 kernel: [ 0.001575] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 0.003026] cgroup: Disabling memory control group subsystem Sep 22 15:18:18 rolyspi2 kernel: [ 0.003256] CPU: Testing write buffer coherency: ok Sep 22 15:18:18 rolyspi2 kernel: [ 0.003709] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Sep 22 15:18:18 rolyspi2 kernel: [ 0.004899] Setting up static identity map for 0x200000 - 0x20003c Sep 22 15:18:18 rolyspi2 systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Sep 22 15:18:18 rolyspi2 kernel: [ 0.005095] rcu: Hierarchical SRCU implementation. Sep 22 15:18:18 rolyspi2 kernel: [ 0.006010] smp: Bringing up secondary CPUs ... Sep 22 15:18:18 rolyspi2 kernel: [ 0.007175] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Sep 22 15:18:18 rolyspi2 rfkill: unblock set for all Sep 22 15:18:18 rolyspi2 kernel: [ 0.008499] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Sep 22 15:18:18 rolyspi2 kernel: [ 0.009772] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Sep 22 15:18:18 rolyspi2 kernel: [ 0.009930] smp: Brought up 1 node, 4 CPUs Sep 22 15:18:18 rolyspi2 systemd[1]: Started Regular background program processing daemon. Sep 22 15:18:18 rolyspi2 kernel: [ 0.009951] SMP: Total of 4 processors activated (432.00 BogoMIPS). Sep 22 15:18:18 rolyspi2 kernel: [ 0.009966] CPU: All CPU(s) started in HYP mode. Sep 22 15:18:18 rolyspi2 kernel: [ 0.009980] CPU: Virtualization extensions available. Sep 22 15:18:18 rolyspi2 kernel: [ 0.010785] devtmpfs: initialized Sep 22 15:18:18 rolyspi2 kernel: [ 0.025275] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Sep 22 15:18:18 rolyspi2 systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)... Sep 22 15:18:18 rolyspi2 kernel: [ 0.025490] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Sep 22 15:18:18 rolyspi2 systemd[1]: Started Manage Sound Card State (restore and store). Sep 22 15:18:18 rolyspi2 kernel: [ 0.025520] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 0.033729] pinctrl core: initialized pinctrl subsystem Sep 22 15:18:18 rolyspi2 kernel: [ 0.034815] NET: Registered protocol family 16 Sep 22 15:18:18 rolyspi2 kernel: [ 0.038548] DMA: preallocated 1024 KiB pool for atomic coherent allocations Sep 22 15:18:18 rolyspi2 kernel: [ 0.039322] audit: initializing netlink subsys (disabled) Sep 22 15:18:18 rolyspi2 kernel: [ 0.039580] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 Sep 22 15:18:18 rolyspi2 cron[394]: (CRON) INFO (pidfile fd = 3) Sep 22 15:18:18 rolyspi2 kernel: [ 0.040152] thermal_sys: Registered thermal governor 'step_wise' Sep 22 15:18:18 rolyspi2 kernel: [ 0.041040] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Sep 22 15:18:18 rolyspi2 kernel: [ 0.041057] hw-breakpoint: maximum watchpoint size is 8 bytes. Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Sep 22 15:18:18 rolyspi2 kernel: [ 0.041458] Serial: AMBA PL011 UART driver Sep 22 15:18:18 rolyspi2 kernel: [ 0.077211] bcm2835-mbox fe00b880.mailbox: mailbox enabled Sep 22 15:18:18 rolyspi2 kernel: [ 0.090843] raspberrypi-firmware soc:firmware: Attached to firmware from 2023-05-09T12:16:34, variant start Sep 22 15:18:18 rolyspi2 kernel: [ 0.100855] raspberrypi-firmware soc:firmware: Firmware hash is 30aa0d70ab280427ba04ebc718c81d4350b9d394 Sep 22 15:18:18 rolyspi2 kernel: [ 0.141355] Kprobes globally optimized Sep 22 15:18:18 rolyspi2 kernel: [ 0.146857] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Sep 22 15:18:18 rolyspi2 start-ap-managed-wifi.sh[383]: net.ipv4.ip_forward = 1 Sep 22 15:18:18 rolyspi2 kernel: [ 0.151127] vgaarb: loaded Sep 22 15:18:18 rolyspi2 kernel: [ 0.151566] SCSI subsystem initialized Sep 22 15:18:18 rolyspi2 kernel: [ 0.151789] usbcore: registered new interface driver usbfs Sep 22 15:18:18 rolyspi2 kernel: [ 0.151850] usbcore: registered new interface driver hub Sep 22 15:18:18 rolyspi2 systemd[1]: Starting rng-tools.service... Sep 22 15:18:18 rolyspi2 kernel: [ 0.151933] usbcore: registered new device driver usb Sep 22 15:18:18 rolyspi2 kernel: [ 0.152295] usb_phy_generic phy: supply vcc not found, using dummy regulator Sep 22 15:18:18 rolyspi2 kernel: [ 0.154268] clocksource: Switched to clocksource arch_sys_counter Sep 22 15:18:18 rolyspi2 kernel: [ 1.099955] VFS: Disk quotas dquot_6.6.0 Sep 22 15:18:18 rolyspi2 kernel: [ 1.100048] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Save/Restore Sound Card State... Sep 22 15:18:18 rolyspi2 kernel: [ 1.100210] FS-Cache: Loaded Sep 22 15:18:18 rolyspi2 kernel: [ 1.100410] CacheFiles: Loaded Sep 22 15:18:18 rolyspi2 kernel: [ 1.101458] simple-framebuffer 3e513000.framebuffer: framebuffer at 0x3e513000, 0x6e7000 bytes, mapped to 0x(ptrval) Sep 22 15:18:18 rolyspi2 kernel: [ 1.101478] simple-framebuffer 3e513000.framebuffer: format=a8r8g8b8, mode=1824x984x32, linelength=7296 Sep 22 15:18:18 rolyspi2 kernel: [ 1.101963] Console: switching to colour frame buffer device 228x61 Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped. Sep 22 15:18:18 rolyspi2 alsactl[398]: alsactl 1.1.8 daemon started Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Disk Manager... Sep 22 15:18:18 rolyspi2 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Sep 22 15:18:18 rolyspi2 cron[394]: (CRON) INFO (Running @reboot jobs) Sep 22 15:18:18 rolyspi2 systemd[1]: Starting System Logging Service... Sep 22 15:18:18 rolyspi2 systemd[1]: Started D-Bus System Message Bus. Sep 22 15:18:18 rolyspi2 rng-tools[403]: Starting Hardware RNG entropy gatherer daemon: rngd. Sep 22 15:18:18 rolyspi2 rngd[418]: rngd 2-unofficial-mt.14 starting up... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting triggerhappy global hotkey daemon... Sep 22 15:18:18 rolyspi2 systemd[1]: Started Daily Cleanup of Temporary Directories. Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Timers. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting dhcpcd on all interfaces... Sep 22 15:18:18 rolyspi2 rngd[418]: entropy feed to the kernel ready Sep 22 15:18:18 rolyspi2 systemd[1]: Starting WPA supplicant... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Check for Raspberry Pi EEPROM updates... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Check for v3d driver... Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Sep 22 15:18:18 rolyspi2 thd[425]: Found socket passed from systemd Sep 22 15:18:18 rolyspi2 thd[425]: Device /dev/input/event4 not suitable. Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Login Service... Sep 22 15:18:18 rolyspi2 systemd[1]: Started rng-tools.service. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Save/Restore Sound Card State. Sep 22 15:18:18 rolyspi2 systemd[1]: Started Check for v3d driver. Sep 22 15:18:18 rolyspi2 kernel: [ 1.110627] simple-framebuffer 3e513000.framebuffer: fb0: simplefb registered! Sep 22 15:18:18 rolyspi2 kernel: [ 1.120763] NET: Registered protocol family 2 Sep 22 15:18:18 rolyspi2 systemd[1]: Started triggerhappy global hotkey daemon. Sep 22 15:18:18 rolyspi2 kernel: [ 1.120980] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 1.122464] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 1.122507] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 1.122571] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) Sep 22 15:18:18 rolyspi2 systemd[1]: Started Helper to synchronize boot up for ifupdown. Sep 22 15:18:18 rolyspi2 kernel: [ 1.122638] TCP: Hash tables configured (established 8192 bind 8192) Sep 22 15:18:18 rolyspi2 kernel: [ 1.122795] UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 1.122832] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Sep 22 15:18:18 rolyspi2 kernel: [ 1.123060] NET: Registered protocol family 1 Sep 22 15:18:18 rolyspi2 kernel: [ 1.124152] RPC: Registered named UNIX socket transport module. Sep 22 15:18:18 rolyspi2 dphys-swapfile[390]: want /var/swap=100MByte, checking existing: keeping it Sep 22 15:18:18 rolyspi2 kernel: [ 1.124168] RPC: Registered udp transport module. Sep 22 15:18:18 rolyspi2 kernel: [ 1.124183] RPC: Registered tcp transport module. Sep 22 15:18:18 rolyspi2 kernel: [ 1.124198] RPC: Registered tcp NFSv4.1 backchannel transport module. Sep 22 15:18:18 rolyspi2 kernel: [ 1.124221] PCI: CLS 0 bytes, default 64 Sep 22 15:18:18 rolyspi2 kernel: [ 1.127324] Initialise system trusted keyrings Sep 22 15:18:18 rolyspi2 kernel: [ 1.127559] workingset: timestamp_bits=14 max_order=21 bucket_order=7 Sep 22 15:18:18 rolyspi2 kernel: [ 1.135866] zbud: loaded Sep 22 15:18:18 rolyspi2 kernel: [ 1.137674] FS-Cache: Netfs 'nfs' registered for caching Sep 22 15:18:18 rolyspi2 dhcpcd[426]: dev: loaded udev Sep 22 15:18:18 rolyspi2 avahi-daemon[439]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113). Sep 22 15:18:18 rolyspi2 avahi-daemon[439]: Successfully dropped root privileges. Sep 22 15:18:18 rolyspi2 rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.1901.0] Sep 22 15:18:18 rolyspi2 udisksd[406]: udisks daemon version 2.8.1 starting Sep 22 15:18:18 rolyspi2 rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="409" x-info="https://www.rsyslog.com"] start Sep 22 15:18:18 rolyspi2 avahi-daemon[439]: avahi-daemon 0.7 starting up. Sep 22 15:18:18 rolyspi2 systemd[1]: Started System Logging Service. Sep 22 15:18:18 rolyspi2 kernel: [ 1.138441] NFS: Registering the id_resolver key type Sep 22 15:18:18 rolyspi2 kernel: [ 1.138513] Key type id_resolver registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.138529] Key type id_legacy registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.138654] nfs4filelayout_init: NFSv4 File Layout Driver Registering... Sep 22 15:18:18 rolyspi2 kernel: [ 1.138671] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Sep 22 15:18:18 rolyspi2 kernel: [ 1.139694] Key type asymmetric registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.139711] Asymmetric key parser 'x509' registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.139904] bounce: pool size: 64 pages Sep 22 15:18:18 rolyspi2 kernel: [ 1.139947] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) Sep 22 15:18:18 rolyspi2 kernel: [ 1.140168] io scheduler mq-deadline registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.140185] io scheduler kyber registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.144690] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Sep 22 15:18:18 rolyspi2 kernel: [ 1.144723] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Sep 22 15:18:18 rolyspi2 kernel: [ 1.144803] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Sep 22 15:18:18 rolyspi2 kernel: [ 1.144892] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 Sep 22 15:18:18 rolyspi2 kernel: [ 1.206373] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Sep 22 15:18:18 rolyspi2 kernel: [ 1.206758] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Sep 22 15:18:18 rolyspi2 kernel: [ 1.206779] pci_bus 0000:00: root bus resource [bus 00-ff] Sep 22 15:18:18 rolyspi2 kernel: [ 1.206801] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Sep 22 15:18:18 rolyspi2 kernel: [ 1.206890] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Sep 22 15:18:18 rolyspi2 kernel: [ 1.207131] pci 0000:00:00.0: PME# supported from D0 D3hot Sep 22 15:18:18 rolyspi2 kernel: [ 1.210706] PCI: bus0: Fast back to back transfers disabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.211046] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Sep 22 15:18:18 rolyspi2 kernel: [ 1.211172] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Sep 22 15:18:18 rolyspi2 kernel: [ 1.211606] pci 0000:01:00.0: PME# supported from D0 D3hot Sep 22 15:18:18 rolyspi2 kernel: [ 1.215183] PCI: bus1: Fast back to back transfers disabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.215279] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Sep 22 15:18:18 rolyspi2 kernel: [ 1.215304] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Sep 22 15:18:18 rolyspi2 kernel: [ 1.215386] pci 0000:00:00.0: PCI bridge to [bus 01] Sep 22 15:18:18 rolyspi2 kernel: [ 1.215412] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Sep 22 15:18:18 rolyspi2 kernel: [ 1.215818] pcieport 0000:00:00.0: enabling device (0140 -> 0142) Sep 22 15:18:18 rolyspi2 kernel: [ 1.216036] pcieport 0000:00:00.0: PME: Signaling with IRQ 66 Sep 22 15:18:18 rolyspi2 kernel: [ 1.222223] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.223125] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default Sep 22 15:18:18 rolyspi2 kernel: [ 1.225743] iproc-rng200 fe104000.rng: hwrng registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.226059] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Sep 22 15:18:18 rolyspi2 kernel: [ 1.226948] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 Sep 22 15:18:18 rolyspi2 kernel: [ 1.238984] brd: module loaded Sep 22 15:18:18 rolyspi2 kernel: [ 1.251151] loop: module loaded Sep 22 15:18:18 rolyspi2 kernel: [ 1.252907] Loading iSCSI transport class v2.0-870. Sep 22 15:18:18 rolyspi2 kernel: [ 1.257877] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Sep 22 15:18:18 rolyspi2 kernel: [ 1.354453] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Sep 22 15:18:18 rolyspi2 kernel: [ 1.355640] usbcore: registered new interface driver r8152 Sep 22 15:18:18 rolyspi2 kernel: [ 1.355709] usbcore: registered new interface driver lan78xx Sep 22 15:18:18 rolyspi2 kernel: [ 1.355770] usbcore: registered new interface driver smsc95xx Sep 22 15:18:18 rolyspi2 kernel: [ 1.401886] xhci_hcd 0000:01:00.0: xHCI Host Controller Sep 22 15:18:18 rolyspi2 kernel: [ 1.401923] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Sep 22 15:18:18 rolyspi2 kernel: [ 1.405098] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000060000000890 Sep 22 15:18:18 rolyspi2 kernel: [ 1.406411] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 Sep 22 15:18:18 rolyspi2 kernel: [ 1.406430] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 22 15:18:18 rolyspi2 kernel: [ 1.406447] usb usb1: Product: xHCI Host Controller Sep 22 15:18:18 rolyspi2 kernel: [ 1.406464] usb usb1: Manufacturer: Linux 5.10.103-v7l+ xhci-hcd Sep 22 15:18:18 rolyspi2 kernel: [ 1.406480] usb usb1: SerialNumber: 0000:01:00.0 Sep 22 15:18:18 rolyspi2 kernel: [ 1.407232] hub 1-0:1.0: USB hub found Sep 22 15:18:18 rolyspi2 kernel: [ 1.407332] hub 1-0:1.0: 1 port detected Sep 22 15:18:18 rolyspi2 kernel: [ 1.408010] xhci_hcd 0000:01:00.0: xHCI Host Controller Sep 22 15:18:18 rolyspi2 kernel: [ 1.408037] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Sep 22 15:18:18 rolyspi2 kernel: [ 1.408062] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Sep 22 15:18:18 rolyspi2 kernel: [ 1.408563] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 Sep 22 15:18:18 rolyspi2 kernel: [ 1.408582] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 22 15:18:18 rolyspi2 kernel: [ 1.408599] usb usb2: Product: xHCI Host Controller Sep 22 15:18:18 rolyspi2 kernel: [ 1.408615] usb usb2: Manufacturer: Linux 5.10.103-v7l+ xhci-hcd Sep 22 15:18:18 rolyspi2 kernel: [ 1.408631] usb usb2: SerialNumber: 0000:01:00.0 Sep 22 15:18:18 rolyspi2 kernel: [ 1.409343] hub 2-0:1.0: USB hub found Sep 22 15:18:18 rolyspi2 kernel: [ 1.409416] hub 2-0:1.0: 4 ports detected Sep 22 15:18:18 rolyspi2 kernel: [ 1.411119] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Sep 22 15:18:18 rolyspi2 kernel: [ 1.411458] dwc_otg: FIQ enabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.411472] dwc_otg: NAK holdoff enabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.411487] dwc_otg: FIQ split-transaction FSM enabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.411505] Module dwc_common_port init Sep 22 15:18:18 rolyspi2 kernel: [ 1.411947] usbcore: registered new interface driver uas Sep 22 15:18:18 rolyspi2 kernel: [ 1.412054] usbcore: registered new interface driver usb-storage Sep 22 15:18:18 rolyspi2 kernel: [ 1.412265] mousedev: PS/2 mouse device common for all mice Sep 22 15:18:18 rolyspi2 kernel: [ 1.414005] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Sep 22 15:18:18 rolyspi2 kernel: [ 1.417383] sdhci: Secure Digital Host Controller Interface driver Sep 22 15:18:18 rolyspi2 kernel: [ 1.417399] sdhci: Copyright(c) Pierre Ossman Sep 22 15:18:18 rolyspi2 kernel: [ 1.418132] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe Sep 22 15:18:18 rolyspi2 kernel: [ 1.418811] sdhci-pltfm: SDHCI platform and OF driver helper Sep 22 15:18:18 rolyspi2 kernel: [ 1.422920] ledtrig-cpu: registered to indicate activity on CPUs Sep 22 15:18:18 rolyspi2 kernel: [ 1.423276] hid: raw HID events driver (C) Jiri Kosina Sep 22 15:18:18 rolyspi2 kernel: [ 1.423458] usbcore: registered new interface driver usbhid Sep 22 15:18:18 rolyspi2 kernel: [ 1.423472] usbhid: USB HID core driver Sep 22 15:18:18 rolyspi2 kernel: [ 1.428845] Initializing XFRM netlink socket Sep 22 15:18:18 rolyspi2 kernel: [ 1.428888] NET: Registered protocol family 17 Sep 22 15:18:18 rolyspi2 kernel: [ 1.429009] Key type dns_resolver registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.429461] Registering SWP/SWPB emulation handler Sep 22 15:18:18 rolyspi2 kernel: [ 1.429651] registered taskstats version 1 Sep 22 15:18:18 rolyspi2 kernel: [ 1.429681] Loading compiled-in X.509 certificates Sep 22 15:18:18 rolyspi2 kernel: [ 1.430501] Key type ._fscrypt registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.430518] Key type .fscrypt registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.430533] Key type fscrypt-provisioning registered Sep 22 15:18:18 rolyspi2 kernel: [ 1.442366] uart-pl011 fe201000.serial: there is not valid maps for state default Sep 22 15:18:18 rolyspi2 kernel: [ 1.442678] uart-pl011 fe201000.serial: cts_event_workaround enabled Sep 22 15:18:18 rolyspi2 kernel: [ 1.442750] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2 Sep 22 15:18:18 rolyspi2 kernel: [ 1.449166] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default Sep 22 15:18:18 rolyspi2 kernel: [ 1.450050] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 38, base_baud = 62500000) is a 16550 Sep 22 15:18:18 rolyspi2 kernel: [ 1.451037] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Sep 22 15:18:18 rolyspi2 kernel: [ 1.452092] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Sep 22 15:18:18 rolyspi2 kernel: [ 1.452109] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Sep 22 15:18:18 rolyspi2 kernel: [ 1.481748] of_cfs_init Sep 22 15:18:18 rolyspi2 kernel: [ 1.482016] of_cfs_init: OK Sep 22 15:18:18 rolyspi2 kernel: [ 1.502407] mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Sep 22 15:18:18 rolyspi2 kernel: [ 1.504113] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Sep 22 15:18:18 rolyspi2 kernel: [ 1.505805] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Sep 22 15:18:18 rolyspi2 kernel: [ 1.508821] mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Sep 22 15:18:18 rolyspi2 kernel: [ 1.510506] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Sep 22 15:18:18 rolyspi2 kernel: [ 1.518560] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Sep 22 15:18:18 rolyspi2 kernel: [ 1.519210] Waiting for root device PARTUUID=389d8ea4-02... Sep 22 15:18:18 rolyspi2 kernel: [ 1.594022] mmc1: new high speed SDIO card at address 0001 Sep 22 15:18:18 rolyspi2 kernel: [ 1.625364] mmc0: new ultra high speed DDR50 SDHC card at address aaaa Sep 22 15:18:18 rolyspi2 kernel: [ 1.626201] mmcblk0: mmc0:aaaa SC32G 29.7 GiB Sep 22 15:18:18 rolyspi2 kernel: [ 1.628850] mmcblk0: p1 p2 Sep 22 15:18:18 rolyspi2 kernel: [ 1.642365] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Sep 22 15:18:18 rolyspi2 kernel: [ 1.642433] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. Sep 22 15:18:18 rolyspi2 kernel: [ 1.649851] devtmpfs: mounted Sep 22 15:18:18 rolyspi2 kernel: [ 1.660063] Freeing unused kernel memory: 2048K Sep 22 15:18:18 rolyspi2 kernel: [ 1.704311] usb 1-1: new high-speed USB device number 2 using xhci_hcd Sep 22 15:18:18 rolyspi2 kernel: [ 1.724632] Run /sbin/init as init process Sep 22 15:18:18 rolyspi2 kernel: [ 1.724647] with arguments: Sep 22 15:18:18 rolyspi2 kernel: [ 1.724661] /sbin/init Sep 22 15:18:18 rolyspi2 kernel: [ 1.724676] splash Sep 22 15:18:18 rolyspi2 kernel: [ 1.724690] with environment: Sep 22 15:18:18 rolyspi2 kernel: [ 1.724704] HOME=/ Sep 22 15:18:18 rolyspi2 kernel: [ 1.724718] TERM=linux Sep 22 15:18:18 rolyspi2 kernel: [ 1.897093] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Sep 22 15:18:18 rolyspi2 kernel: [ 1.897115] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Sep 22 15:18:18 rolyspi2 kernel: [ 1.897154] usb 1-1: Product: USB2.0 Hub Sep 22 15:18:18 rolyspi2 kernel: [ 1.899177] hub 1-1:1.0: USB hub found Sep 22 15:18:18 rolyspi2 kernel: [ 1.899762] hub 1-1:1.0: 4 ports detected Sep 22 15:18:18 rolyspi2 kernel: [ 2.234338] usb 1-1.1: new full-speed USB device number 3 using xhci_hcd Sep 22 15:18:18 rolyspi2 kernel: [ 2.263187] NET: Registered protocol family 10 Sep 22 15:18:18 rolyspi2 kernel: [ 2.264618] Segment Routing with IPv6 Sep 22 15:18:18 rolyspi2 kernel: [ 2.378734] usb 1-1.1: New USB device found, idVendor=1547, idProduct=1000, bcdDevice= 0.01 Sep 22 15:18:18 rolyspi2 kernel: [ 2.378754] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 22 15:18:18 rolyspi2 kernel: [ 2.378771] usb 1-1.1: Product: SG-Lock USB Key Sep 22 15:18:18 rolyspi2 kernel: [ 2.378788] usb 1-1.1: Manufacturer: SG-Lock Sep 22 15:18:18 rolyspi2 kernel: [ 2.386085] hid-generic 0003:1547:1000.0001: hiddev96,hidraw0: USB HID v1.00 Device [SG-Lock SG-Lock USB Key] on usb-0000:01:00.0-1.1/input0 Sep 22 15:18:18 rolyspi2 kernel: [ 2.494366] usb 1-1.3: new low-speed USB device number 4 using xhci_hcd Sep 22 15:18:18 rolyspi2 kernel: [ 2.662778] usb 1-1.3: New USB device found, idVendor=0e8f, idProduct=00a8, bcdDevice= 3.11 Sep 22 15:18:18 rolyspi2 kernel: [ 2.662801] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 22 15:18:18 rolyspi2 kernel: [ 2.662819] usb 1-1.3: Product: 2.4G RX Sep 22 15:18:18 rolyspi2 kernel: [ 2.662836] usb 1-1.3: Manufacturer: DaKai Sep 22 15:18:18 rolyspi2 kernel: [ 2.674413] input: DaKai 2.4G RX as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/0003:0E8F:00A8.0002/input/input0 Sep 22 15:18:18 rolyspi2 kernel: [ 2.745072] hid-generic 0003:0E8F:00A8.0002: input,hidraw1: USB HID v1.10 Keyboard [DaKai 2.4G RX] on usb-0000:01:00.0-1.3/input0 Sep 22 15:18:18 rolyspi2 kernel: [ 2.757843] input: DaKai 2.4G RX Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input1 Sep 22 15:18:18 rolyspi2 kernel: [ 2.758329] input: DaKai 2.4G RX System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input2 Sep 22 15:18:18 rolyspi2 kernel: [ 2.834829] input: DaKai 2.4G RX Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input3 Sep 22 15:18:18 rolyspi2 kernel: [ 2.835121] input: DaKai 2.4G RX as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input4 Sep 22 15:18:18 rolyspi2 kernel: [ 2.835548] hid-generic 0003:0E8F:00A8.0003: input,hiddev97,hidraw2: USB HID v1.10 Mouse [DaKai 2.4G RX] on usb-0000:01:00.0-1.3/input1 Sep 22 15:18:18 rolyspi2 kernel: [ 2.954365] usb 1-1.4: new full-speed USB device number 5 using xhci_hcd Sep 22 15:18:18 rolyspi2 kernel: [ 3.098850] usb 1-1.4: New USB device found, idVendor=067b, idProduct=2303, bcdDevice= 4.00 Sep 22 15:18:18 rolyspi2 kernel: [ 3.098871] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 22 15:18:18 rolyspi2 kernel: [ 3.098888] usb 1-1.4: Product: USB-Serial Controller D Sep 22 15:18:18 rolyspi2 kernel: [ 3.098905] usb 1-1.4: Manufacturer: Prolific Technology Inc. Sep 22 15:18:18 rolyspi2 kernel: [ 3.150423] random: systemd: uninitialized urandom read (16 bytes read) Sep 22 15:18:18 rolyspi2 kernel: [ 3.164211] random: systemd: uninitialized urandom read (16 bytes read) Sep 22 15:18:18 rolyspi2 kernel: [ 3.165623] random: systemd: uninitialized urandom read (16 bytes read) Sep 22 15:18:18 rolyspi2 kernel: [ 3.804027] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null) Sep 22 15:18:18 rolyspi2 kernel: [ 4.561546] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 Sep 22 15:18:18 rolyspi2 kernel: [ 4.563127] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 Sep 22 15:18:18 rolyspi2 kernel: [ 4.565607] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 Sep 22 15:18:18 rolyspi2 kernel: [ 4.570075] gpio-fan gpio-fan@0: GPIO fan initialized Sep 22 15:18:18 rolyspi2 kernel: [ 4.570446] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 Sep 22 15:18:18 rolyspi2 kernel: [ 4.768093] mc: Linux media interface: v0.10 Sep 22 15:18:18 rolyspi2 kernel: [ 4.794327] videodev: Linux video capture interface: v2.00 Sep 22 15:18:18 rolyspi2 kernel: [ 4.844616] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:18:18 rolyspi2 kernel: [ 4.847047] bcm2835_vc_sm_cma_probe: Videocore shared memory driver Sep 22 15:18:18 rolyspi2 kernel: [ 4.847073] [vc_sm_connected_init]: start Sep 22 15:18:18 rolyspi2 kernel: [ 4.855981] [vc_sm_connected_init]: installed successfully Sep 22 15:18:18 rolyspi2 kernel: [ 4.860525] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:18:18 rolyspi2 kernel: [ 4.867965] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:18:18 rolyspi2 kernel: [ 4.883189] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Sep 22 15:18:18 rolyspi2 kernel: [ 4.883563] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Sep 22 15:18:18 rolyspi2 kernel: [ 4.883871] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Sep 22 15:18:18 rolyspi2 kernel: [ 4.884145] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Sep 22 15:18:18 rolyspi2 kernel: [ 4.884177] bcm2835-isp bcm2835-isp: Register output node 0 with media controller Sep 22 15:18:18 rolyspi2 kernel: [ 4.884215] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Sep 22 15:18:18 rolyspi2 kernel: [ 4.884238] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Sep 22 15:18:18 rolyspi2 kernel: [ 4.884304] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Sep 22 15:18:18 rolyspi2 kernel: [ 4.884504] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Sep 22 15:18:18 rolyspi2 kernel: [ 4.937604] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:18:18 rolyspi2 kernel: [ 5.113186] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:18:18 rolyspi2 kernel: [ 5.148984] bcm2835_audio bcm2835_audio: card created with 4 channels Sep 22 15:18:18 rolyspi2 kernel: [ 5.152044] bcm2835_audio bcm2835_audio: card created with 4 channels Sep 22 15:18:18 rolyspi2 kernel: [ 5.266384] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:18:18 rolyspi2 kernel: [ 5.294791] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Sep 22 15:18:18 rolyspi2 kernel: [ 5.294838] bcm2835-codec bcm2835-codec: Loaded V4L2 decode Sep 22 15:18:18 rolyspi2 kernel: [ 5.302952] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Sep 22 15:18:18 rolyspi2 kernel: [ 5.302998] bcm2835-codec bcm2835-codec: Loaded V4L2 encode Sep 22 15:18:18 rolyspi2 kernel: [ 5.310416] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Sep 22 15:18:18 rolyspi2 kernel: [ 5.310476] bcm2835-codec bcm2835-codec: Loaded V4L2 isp Sep 22 15:18:18 rolyspi2 kernel: [ 5.334492] bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Sep 22 15:18:18 rolyspi2 kernel: [ 5.334540] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Sep 22 15:18:18 rolyspi2 kernel: [ 5.355087] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0 Sep 22 15:18:18 rolyspi2 kernel: [ 5.406540] checking generic (3e513000 6e7000) vs hw (0 ffffffffffffffff) Sep 22 15:18:18 rolyspi2 kernel: [ 5.406592] fb0: switching to vc4drmfb from simple Sep 22 15:18:18 rolyspi2 kernel: [ 5.408384] Console: switching to colour dummy device 80x30 Sep 22 15:18:18 rolyspi2 kernel: [ 5.411137] [drm] forcing HDMI-A-1 connector on Sep 22 15:18:18 rolyspi2 kernel: [ 5.411474] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4]) Sep 22 15:18:18 rolyspi2 kernel: [ 5.412360] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 1 Sep 22 15:18:18 rolyspi2 kernel: [ 5.474240] Console: switching to colour frame buffer device 240x67 Sep 22 15:18:18 rolyspi2 kernel: [ 5.474326] vc4-drm gpu: [drm] fb0: vc4drmfb frame buffer device Sep 22 15:18:18 rolyspi2 kernel: [ 5.491294] usbcore: registered new interface driver usbserial_generic Sep 22 15:18:18 rolyspi2 kernel: [ 5.491371] usbserial: USB Serial support registered for generic Sep 22 15:18:18 rolyspi2 kernel: [ 5.571965] cfg80211: Loading compiled-in X.509 certificates for regulatory database Sep 22 15:18:18 rolyspi2 kernel: [ 5.573838] usbcore: registered new interface driver pl2303 Sep 22 15:18:18 rolyspi2 kernel: [ 5.573922] usbserial: USB Serial support registered for pl2303 Sep 22 15:18:18 rolyspi2 kernel: [ 5.574063] pl2303 1-1.4:1.0: pl2303 converter detected Sep 22 15:18:18 rolyspi2 kernel: [ 5.604207] usb 1-1.4: pl2303 converter now attached to ttyUSB0 Sep 22 15:18:18 rolyspi2 kernel: [ 5.627011] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Sep 22 15:18:18 rolyspi2 kernel: [ 5.648572] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid Sep 22 15:18:18 rolyspi2 kernel: [ 5.682619] brcmfmac: F1 signature read @0x18000000=0x15264345 Sep 22 15:18:18 rolyspi2 kernel: [ 5.693951] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Sep 22 15:18:18 rolyspi2 kernel: [ 5.694974] usbcore: registered new interface driver brcmfmac Sep 22 15:18:18 rolyspi2 kernel: [ 5.969834] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Sep 22 15:18:18 rolyspi2 kernel: [ 5.975827] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Sep 22 15:18:18 rolyspi2 kernel: [ 6.512892] brcmfmac mmc1:0001:1 wlan9: renamed from wlan0 Sep 22 15:18:18 rolyspi2 kernel: [ 6.717091] CAN device driver interface Sep 22 15:18:18 rolyspi2 kernel: [ 7.746478] mcp251x spi0.0: MCP251x didn't enter in conf mode after reset Sep 22 15:18:18 rolyspi2 kernel: [ 7.751833] mcp251x spi0.0: Probe failed, err=110 Sep 22 15:18:18 rolyspi2 kernel: [ 7.751932] mcp251x: probe of spi0.0 failed with error -110 Sep 22 15:18:18 rolyspi2 kernel: [ 7.811124] random: crng init done Sep 22 15:18:18 rolyspi2 kernel: [ 7.811145] random: 7 urandom warning(s) missed due to ratelimiting Sep 22 15:18:18 rolyspi2 kernel: [ 7.836772] uart-pl011 fe201000.serial: no DMA platform data Sep 22 15:18:18 rolyspi2 systemd[1]: Starting Raise network interfaces... Sep 22 15:18:18 rolyspi2 systemd[1]: Reached target Sound Card. Sep 22 15:18:18 rolyspi2 raspi-config[396]: Checking if shift key is held down:Device /dev/input/event4 not suitable. Sep 22 15:18:18 rolyspi2 kernel: [ 8.243310] 8021q: 802.1Q VLAN Support v1.8 Sep 22 15:18:18 rolyspi2 dhcpcd[426]: forked to background, child pid 484 Sep 22 15:18:19 rolyspi2 kernel: [ 8.330595] Adding 102396k swap on /var/swap. Priority:-2 extents:5 across:147452k SSFS Sep 22 15:18:19 rolyspi2 systemd[1]: Started dhcpcd on all interfaces. Sep 22 15:18:19 rolyspi2 systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file. Sep 22 15:18:19 rolyspi2 wpa_supplicant[429]: Successfully initialized wpa_supplicant Sep 22 15:18:19 rolyspi2 avahi-daemon[439]: Successfully called chroot(). Sep 22 15:18:19 rolyspi2 avahi-daemon[439]: Successfully dropped remaining capabilities. Sep 22 15:18:19 rolyspi2 systemd[1]: Started Login Service. Sep 22 15:18:19 rolyspi2 systemd[1]: Started WPA supplicant. Sep 22 15:18:19 rolyspi2 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Sep 22 15:18:19 rolyspi2 avahi-daemon[439]: No service file found in /etc/avahi/services. Sep 22 15:18:19 rolyspi2 systemd[1]: Started Make remote CUPS printers available locally. Sep 22 15:18:19 rolyspi2 avahi-daemon[439]: Network interface enumeration completed. Sep 22 15:18:19 rolyspi2 avahi-daemon[439]: Server startup complete. Host name is rolyspi2.local. Local service cookie is 507702872. Sep 22 15:18:19 rolyspi2 udisksd[406]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory Sep 22 15:18:19 rolyspi2 udisksd[406]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory Sep 22 15:18:19 rolyspi2 dhcpcd-run-hooks[538]: wlan9: starting wpa_supplicant Sep 22 15:18:19 rolyspi2 dhcpcd[484]: wlan9: connected to Access Point `' Sep 22 15:18:19 rolyspi2 dhcpcd[484]: eth0: waiting for carrier Sep 22 15:18:19 rolyspi2 udisksd[406]: Failed to load the 'mdraid' libblockdev plugin Sep 22 15:18:19 rolyspi2 udisksd[406]: Failed to load the 'crypto' libblockdev plugin Sep 22 15:18:19 rolyspi2 kernel: [ 8.685249] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Sep 22 15:18:19 rolyspi2 kernel: [ 8.685873] bcmgenet fd580000.ethernet eth0: Link is Down Sep 22 15:18:19 rolyspi2 dbus-daemon[413]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=406 comm="/usr/lib/udisks2/udisksd ") Sep 22 15:18:19 rolyspi2 systemd[1]: Starting Authorization Manager... Sep 22 15:18:19 rolyspi2 kernel: [ 8.738928] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: Skipping automatic bootloader upgrade. current 1599135103 >= min 1599135103 Sep 22 15:18:19 rolyspi2 dhcpcd[484]: wlan9: waiting for carrier Sep 22 15:18:19 rolyspi2 ifup[471]: Cannot find device "can0" Sep 22 15:18:19 rolyspi2 ifup[471]: ifup: failed to bring up can0 Sep 22 15:18:19 rolyspi2 systemd[1]: networking.service: Main process exited, code=exited, status=1/FAILURE Sep 22 15:18:19 rolyspi2 systemd[1]: networking.service: Failed with result 'exit-code'. Sep 22 15:18:19 rolyspi2 systemd[1]: Failed to start Raise network interfaces. Sep 22 15:18:19 rolyspi2 systemd[1]: Reached target Network. Sep 22 15:18:19 rolyspi2 systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Sep 22 15:18:19 rolyspi2 systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Sep 22 15:18:19 rolyspi2 systemd[1]: Starting OpenBSD Secure Shell server... Sep 22 15:18:19 rolyspi2 systemd[1]: Starting /etc/rc.local Compatibility... Sep 22 15:18:19 rolyspi2 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Sep 22 15:18:19 rolyspi2 systemd[1]: Started VNC Server in Service Mode daemon. Sep 22 15:18:19 rolyspi2 systemd[1]: Starting Permit User Sessions... Sep 22 15:18:19 rolyspi2 dnsmasq[597]: dnsmasq: syntax check OK. Sep 22 15:18:19 rolyspi2 systemd[1]: Started /etc/rc.local Compatibility. Sep 22 15:18:19 rolyspi2 polkitd[558]: started daemon version 0.105 using authority implementation `local' version `0.105' Sep 22 15:18:19 rolyspi2 dbus-daemon[413]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Sep 22 15:18:19 rolyspi2 systemd[1]: Started Authorization Manager. Sep 22 15:18:19 rolyspi2 hostapd[596]: Configuration file: /etc/hostapd/hostapd.conf Sep 22 15:18:19 rolyspi2 systemd[1]: Started Permit User Sessions. Sep 22 15:18:19 rolyspi2 systemd[1]: Starting Light Display Manager... Sep 22 15:18:19 rolyspi2 systemd[1]: Starting Hold until boot process finishes up... Sep 22 15:18:19 rolyspi2 hostapd[596]: wlan9: interface state UNINITIALIZED->HT_SCAN Sep 22 15:18:19 rolyspi2 systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: BOOTLOADER: up to date Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: CURRENT: Thu 3 Sep 12:11:43 UTC 2020 (1599135103) Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: LATEST: Wed 11 Jan 17:40:52 UTC 2023 (1673458852) Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: RELEASE: default (/lib/firmware/raspberrypi/bootloader/default) Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: Use raspi-config to change the release. Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: VL805_FW: Using bootloader EEPROM Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: VL805: up to date Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: CURRENT: 000138a1 Sep 22 15:18:19 rolyspi2 rpi-eeprom-update[430]: LATEST: 000138a1 Sep 22 15:18:19 rolyspi2 systemd[1]: Started Check for Raspberry Pi EEPROM updates. Sep 22 15:18:20 rolyspi2 systemd[1]: Started OpenBSD Secure Shell server. Sep 22 15:18:20 rolyspi2 lightdm[611]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files Sep 22 15:18:20 rolyspi2 raspi-config[396]: No. Switching to ondemand scaling governor. Sep 22 15:18:20 rolyspi2 systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed). Sep 22 15:18:20 rolyspi2 dnsmasq[632]: started, version 2.80 cachesize 150 Sep 22 15:18:20 rolyspi2 dnsmasq[632]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Sep 22 15:18:20 rolyspi2 dnsmasq[632]: warning: interface wlan9 does not currently exist Sep 22 15:18:20 rolyspi2 dnsmasq-dhcp[632]: DHCP, IP range 10.10.10.50 -- 10.10.10.200, lease time 12h Sep 22 15:18:20 rolyspi2 dnsmasq[632]: read /etc/hosts - 6 addresses Sep 22 15:18:20 rolyspi2 systemd[1]: Received SIGRTMIN+21 from PID 170 (plymouthd). Sep 22 15:18:20 rolyspi2 systemd[1]: Received SIGRTMIN+21 from PID 170 (plymouthd). Sep 22 15:18:20 rolyspi2 systemd[1]: plymouth-quit-wait.service: Succeeded. Sep 22 15:18:20 rolyspi2 systemd[1]: Started Hold until boot process finishes up. Sep 22 15:18:20 rolyspi2 systemd[1]: Started Getty on tty1. Sep 22 15:18:20 rolyspi2 udisksd[406]: Acquired the name org.freedesktop.UDisks2 on the system message bus Sep 22 15:18:20 rolyspi2 systemd[1]: Reached target Login Prompts. Sep 22 15:18:20 rolyspi2 systemd[1]: Started Light Display Manager. Sep 22 15:18:20 rolyspi2 systemd[1]: Started Disk Manager. Sep 22 15:18:20 rolyspi2 systemd[1]: plymouth-start.service: Succeeded. Sep 22 15:18:20 rolyspi2 dnsmasq[632]: no servers found in /run/dnsmasq/resolv.conf, will retry Sep 22 15:18:20 rolyspi2 dhcpcd[484]: wlan9: carrier acquired Sep 22 15:18:20 rolyspi2 kernel: [ 9.531175] IPv6: ADDRCONF(NETDEV_CHANGE): wlan9: link becomes ready Sep 22 15:18:20 rolyspi2 dhcpcd[484]: wlan9: probing address 10.10.10.1/24 Sep 22 15:18:20 rolyspi2 dnsmasq[633]: Too few arguments. Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: LogDestMem: Start replaying stored messages Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: VendorConfig: Error in Certificate "CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US": X.509 Error: Certificate expired Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: VendorConfig: Error in Certificate "CN=GlobalSign,O=GlobalSign,OU=GlobalSign Root CA - R2": X.509 Error: Certificate expired Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: LogDestMem: Finished replaying stored messages Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: ServerManager: Server started Sep 22 15:18:20 rolyspi2 dnsmasq[633]: Too few arguments. Sep 22 15:18:20 rolyspi2 systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Sep 22 15:18:20 rolyspi2 systemd[1]: Reached target Host and Network Name Lookups. Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: SModuleUpdateNotification: Last checked for updates more than 250 days ago Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: ConsoleDisplay: Cannot find a running X server on vt1 Sep 22 15:18:20 rolyspi2 vncserver-x11[610,root]: ConsoleDisplay: Found running X server (pid=667, binary=/usr/lib/xorg/Xorg) Sep 22 15:18:21 rolyspi2 systemd[1]: openplotter-can-read.service: Succeeded. Sep 22 15:18:21 rolyspi2 kernel: [ 11.291185] broken atomic modeset userspace detected, disabling atomic Sep 22 15:18:22 rolyspi2 avahi-daemon[439]: Joining mDNS multicast group on interface wlan9.IPv6 with address fe80::dea6:32ff:fee0:c844. Sep 22 15:18:22 rolyspi2 avahi-daemon[439]: New relevant interface wlan9.IPv6 for mDNS. Sep 22 15:18:22 rolyspi2 avahi-daemon[439]: Registering new address record for fe80::dea6:32ff:fee0:c844 on wlan9.*. Sep 22 15:18:22 rolyspi2 systemd[1]: systemd-rfkill.service: Succeeded. Sep 22 15:18:23 rolyspi2 lightdm[705]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files Sep 22 15:18:23 rolyspi2 systemd[1]: Created slice User Slice of UID 1000. Sep 22 15:18:23 rolyspi2 systemd[1]: Starting User Runtime Directory /run/user/1000... Sep 22 15:18:23 rolyspi2 systemd[1]: Started User Runtime Directory /run/user/1000. Sep 22 15:18:23 rolyspi2 systemd[1]: Starting User Manager for UID 1000... Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on GnuPG network certificate management daemon. Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on GnuPG cryptographic agent and passphrase cache. Sep 22 15:18:24 rolyspi2 systemd[710]: Reached target Timers. Sep 22 15:18:24 rolyspi2 systemd[710]: Starting D-Bus User Message Bus Socket. Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Sep 22 15:18:24 rolyspi2 systemd[710]: Reached target Paths. Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on Sound System. Sep 22 15:18:24 rolyspi2 systemd[710]: Listening on D-Bus User Message Bus Socket. Sep 22 15:18:24 rolyspi2 systemd[710]: Reached target Sockets. Sep 22 15:18:24 rolyspi2 systemd[710]: Reached target Basic System. Sep 22 15:18:24 rolyspi2 systemd[1]: Started User Manager for UID 1000. Sep 22 15:18:24 rolyspi2 systemd[710]: Reached target Default. Sep 22 15:18:24 rolyspi2 systemd[710]: Startup finished in 447ms. Sep 22 15:18:24 rolyspi2 systemd[1]: Started Session 1 of user pi. Sep 22 15:18:24 rolyspi2 systemd[710]: Started D-Bus User Message Bus. Sep 22 15:18:25 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=724 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ") Sep 22 15:18:25 rolyspi2 systemd[710]: Starting Virtual filesystem service... Sep 22 15:18:25 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'org.gtk.vfs.Daemon' Sep 22 15:18:25 rolyspi2 systemd[710]: Started Virtual filesystem service. Sep 22 15:18:25 rolyspi2 kernel: [ 14.451715] fuse: init (API version 7.32) Sep 22 15:18:25 rolyspi2 systemd[1]: Mounting FUSE Control File System... Sep 22 15:18:25 rolyspi2 systemd[1]: Mounted FUSE Control File System. Sep 22 15:18:25 rolyspi2 dhcpcd[484]: wlan9: using static address 10.10.10.1/24 Sep 22 15:18:25 rolyspi2 avahi-daemon[439]: Joining mDNS multicast group on interface wlan9.IPv4 with address 10.10.10.1. Sep 22 15:18:25 rolyspi2 avahi-daemon[439]: New relevant interface wlan9.IPv4 for mDNS. Sep 22 15:18:25 rolyspi2 avahi-daemon[439]: Registering new address record for 10.10.10.1 on wlan9.IPv4. Sep 22 15:18:25 rolyspi2 dhcpcd[484]: wlan9: adding route to 10.10.10.0/24 Sep 22 15:18:25 rolyspi2 dhcpcd[484]: wlan9: adding default route via 10.10.10.1 Sep 22 15:18:25 rolyspi2 systemd[1]: Started Session 3 of user pi. Sep 22 15:18:25 rolyspi2 dnsmasq[632]: reading /run/dnsmasq/resolv.conf Sep 22 15:18:25 rolyspi2 dnsmasq[632]: using nameserver 8.8.8.8#53 Sep 22 15:18:25 rolyspi2 systemd[710]: Starting Sound Service... Sep 22 15:18:25 rolyspi2 dbus-daemon[413]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.21' (uid=1000 pid=885 comm="/usr/bin/pulseaudio --daemonize=no ") Sep 22 15:18:25 rolyspi2 systemd[1]: Starting RealtimeKit Scheduling Policy Service... Sep 22 15:18:25 rolyspi2 dbus-daemon[413]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Successfully called chroot. Sep 22 15:18:25 rolyspi2 systemd[1]: Started RealtimeKit Scheduling Policy Service. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Successfully dropped privileges. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Successfully limited resources. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Running. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Canary thread running. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Watchdog thread running. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Successfully made thread 885 of process 885 (n/a) owned by '1000' high priority at nice level -11. Sep 22 15:18:25 rolyspi2 rtkit-daemon[902]: Supervising 1 threads of 1 processes of 1 users. Sep 22 15:18:25 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=810 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:18:25 rolyspi2 systemd[710]: Starting Virtual filesystem service - disk device monitor... Sep 22 15:18:26 rolyspi2 rtkit-daemon[902]: Supervising 1 threads of 1 processes of 1 users. Sep 22 15:18:26 rolyspi2 rtkit-daemon[902]: Successfully made thread 916 of process 885 (n/a) owned by '1000' RT at priority 5. Sep 22 15:18:26 rolyspi2 rtkit-daemon[902]: Supervising 2 threads of 1 processes of 1 users. Sep 22 15:18:26 rolyspi2 rtkit-daemon[902]: Supervising 2 threads of 1 processes of 1 users. Sep 22 15:18:26 rolyspi2 rtkit-daemon[902]: Successfully made thread 917 of process 885 (n/a) owned by '1000' RT at priority 5. Sep 22 15:18:26 rolyspi2 rtkit-daemon[902]: Supervising 3 threads of 1 processes of 1 users. Sep 22 15:18:26 rolyspi2 dbus-daemon[413]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.26' (uid=1000 pid=885 comm="/usr/bin/pulseaudio --daemonize=no ") Sep 22 15:18:26 rolyspi2 systemd[1]: Condition check resulted in Bluetooth service being skipped. Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor' Sep 22 15:18:26 rolyspi2 systemd[710]: Started Virtual filesystem service - disk device monitor. Sep 22 15:18:26 rolyspi2 systemd[710]: Started Sound Service. Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=810 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:18:26 rolyspi2 systemd[710]: Starting Virtual filesystem service - Apple File Conduit monitor... Sep 22 15:18:26 rolyspi2 gvfs-afc-volume-monitor[919]: Volume monitor alive Sep 22 15:18:26 rolyspi2 vncserver-x11[610,root]: SModuleUpdateNotification: Last checked for updates more than 250 days ago Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor' Sep 22 15:18:26 rolyspi2 systemd[710]: Started Virtual filesystem service - Apple File Conduit monitor. Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=810 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:18:26 rolyspi2 systemd[710]: Starting Virtual filesystem service - GNOME Online Accounts monitor... Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor' Sep 22 15:18:26 rolyspi2 systemd[710]: Started Virtual filesystem service - GNOME Online Accounts monitor. Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=810 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:18:26 rolyspi2 systemd[710]: Starting Virtual filesystem service - digital camera monitor... Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor' Sep 22 15:18:26 rolyspi2 systemd[710]: Started Virtual filesystem service - digital camera monitor. Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=810 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:18:26 rolyspi2 systemd[710]: Starting Virtual filesystem service - Media Transfer Protocol monitor... Sep 22 15:18:26 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor' Sep 22 15:18:26 rolyspi2 systemd[710]: Started Virtual filesystem service - Media Transfer Protocol monitor. Sep 22 15:18:26 rolyspi2 kernel: [ 16.035432] Bluetooth: Core ver 2.22 Sep 22 15:18:26 rolyspi2 kernel: [ 16.035502] NET: Registered protocol family 31 Sep 22 15:18:26 rolyspi2 kernel: [ 16.035509] Bluetooth: HCI device and connection manager initialized Sep 22 15:18:26 rolyspi2 kernel: [ 16.035525] Bluetooth: HCI socket layer initialized Sep 22 15:18:26 rolyspi2 kernel: [ 16.035535] Bluetooth: L2CAP socket layer initialized Sep 22 15:18:26 rolyspi2 kernel: [ 16.035556] Bluetooth: SCO socket layer initialized Sep 22 15:18:26 rolyspi2 kernel: [ 16.053140] Bluetooth: HCI UART driver ver 2.3 Sep 22 15:18:26 rolyspi2 kernel: [ 16.053151] Bluetooth: HCI UART protocol H4 registered Sep 22 15:18:26 rolyspi2 kernel: [ 16.053210] Bluetooth: HCI UART protocol Three-wire (H5) registered Sep 22 15:18:26 rolyspi2 kernel: [ 16.053369] Bluetooth: HCI UART protocol Broadcom registered Sep 22 15:18:26 rolyspi2 btuart[382]: bcm43xx_init Sep 22 15:18:26 rolyspi2 btuart[382]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Sep 22 15:18:26 rolyspi2 btuart[382]: Set Controller UART speed to 3000000 bit/s Sep 22 15:18:26 rolyspi2 btuart[382]: Device setup complete Sep 22 15:18:26 rolyspi2 systemd[1]: Starting Load/Save RF Kill Switch Status... Sep 22 15:18:26 rolyspi2 systemd[1]: Started Configure Bluetooth Modems connected by UART. Sep 22 15:18:26 rolyspi2 systemd[1]: Started Load/Save RF Kill Switch Status. Sep 22 15:18:26 rolyspi2 systemd[1]: Created slice system-bthelper.slice. Sep 22 15:18:26 rolyspi2 systemd[1]: Starting Raspberry Pi bluetooth helper... Sep 22 15:18:26 rolyspi2 systemd[1]: Reached target Multi-User System. Sep 22 15:18:26 rolyspi2 systemd[1]: Reached target Graphical Interface. Sep 22 15:18:26 rolyspi2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 22 15:18:26 rolyspi2 bthelper[968]: Raspberry Pi BDADDR already set Sep 22 15:18:26 rolyspi2 systemd[1]: Started Raspberry Pi bluetooth helper. Sep 22 15:18:26 rolyspi2 systemd[1]: Starting Bluetooth service... Sep 22 15:18:26 rolyspi2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 22 15:18:26 rolyspi2 systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Bluetooth daemon 5.50 Sep 22 15:18:27 rolyspi2 dbus-daemon[413]: [system] Successfully activated service 'org.bluez' Sep 22 15:18:27 rolyspi2 systemd[1]: Started Bluetooth service. Sep 22 15:18:27 rolyspi2 systemd[1]: Reached target Bluetooth. Sep 22 15:18:27 rolyspi2 systemd[1]: Startup finished in 2.123s (kernel) + 14.254s (userspace) = 16.378s. Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Starting SDP server Sep 22 15:18:27 rolyspi2 kernel: [ 16.430476] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Sep 22 15:18:27 rolyspi2 kernel: [ 16.430486] Bluetooth: BNEP filters: protocol multicast Sep 22 15:18:27 rolyspi2 kernel: [ 16.430503] Bluetooth: BNEP socket layer initialized Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Bluetooth management interface 1.18 initialized Sep 22 15:18:27 rolyspi2 dbus-daemon[413]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.27' (uid=0 pid=980 comm="/usr/lib/bluetooth/bluetoothd ") Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Sap driver initialization failed. Sep 22 15:18:27 rolyspi2 bluetoothd[980]: sap-server: Operation not permitted (1) Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Endpoint registered: sender=:1.26 path=/MediaEndpoint/A2DPSource Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Endpoint registered: sender=:1.26 path=/MediaEndpoint/A2DPSink Sep 22 15:18:27 rolyspi2 pulseaudio[885]: E: [pulseaudio] bluez5-util.c: Found duplicated D-Bus path for adapter /org/bluez/hci0 Sep 22 15:18:27 rolyspi2 pulseaudio[885]: E: [pulseaudio] backend-ofono.c: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Sep 22 15:18:27 rolyspi2 systemd[1]: Starting Hostname Service... Sep 22 15:18:27 rolyspi2 kernel: [ 16.468358] Bluetooth: RFCOMM TTY layer initialized Sep 22 15:18:27 rolyspi2 kernel: [ 16.468383] Bluetooth: RFCOMM socket layer initialized Sep 22 15:18:27 rolyspi2 kernel: [ 16.468400] Bluetooth: RFCOMM ver 1.11 Sep 22 15:18:27 rolyspi2 bluetoothd[980]: Failed to set privacy: Rejected (0x0b) Sep 22 15:18:27 rolyspi2 dbus-daemon[413]: [system] Successfully activated service 'org.freedesktop.hostname1' Sep 22 15:18:27 rolyspi2 systemd[1]: Started Hostname Service. Sep 22 15:18:30 rolyspi2 kernel: [ 20.144731] can: controller area network core Sep 22 15:18:30 rolyspi2 kernel: [ 20.144854] NET: Registered protocol family 29 Sep 22 15:18:30 rolyspi2 signalk-server[384]: unable to open canbus can0: Error: Error while creating channel Sep 22 15:18:30 rolyspi2 kernel: [ 20.155134] can: raw protocol Sep 22 15:18:30 rolyspi2 signalk-server[384]: Error: Error while creating channel Sep 22 15:18:30 rolyspi2 signalk-server[384]: at Object.exports.createRawChannelWithOptions (/usr/lib/node_modules/signalk-server/node_modules/socketcan/socketcan.js:56:12) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at new CanbusStream (/usr/lib/node_modules/signalk-server/node_modules/@canboat/canboatjs/lib/canbus.js:123:32) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at CanbusStream (/usr/lib/node_modules/signalk-server/node_modules/@canboat/canboatjs/lib/canbus.js:47:12) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at Object.nmea2000input [as NMEA2000] (/usr/lib/node_modules/signalk-server/node_modules/@signalk/streams/simple.js:233:30) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at new Simple (/usr/lib/node_modules/signalk-server/node_modules/@signalk/streams/simple.js:79:34) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at createPipeElement (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:75:16) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at result.pipeElements.providerConfig.pipeElements.reduce (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:48:30) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at Array.reduce () Sep 22 15:18:30 rolyspi2 signalk-server[384]: at createPipedProvider (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:46:55) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at app.config.settings.pipedProviders.reduce (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:82:37) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at Array.reduce () Sep 22 15:18:30 rolyspi2 signalk-server[384]: at Object.startProviders [as start] (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:79:62) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at createServer (/usr/lib/node_modules/signalk-server/lib/index.js:280:66) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at createServer (/usr/lib/node_modules/signalk-server/lib/index.js:398:5) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at Promise (/usr/lib/node_modules/signalk-server/lib/index.js:267:13) Sep 22 15:18:30 rolyspi2 signalk-server[384]: at new Promise () Sep 22 15:18:30 rolyspi2 signalk-server[384]: signalk-server running at 0.0.0.0:[object Object] Sep 22 15:18:30 rolyspi2 signalk-server[384]: Error: No such file or directory, cannot open /dev/serial/by-id/usb-VesperMarine_Vesper_Marine_AIS_VESPERMARINE-if00-port0 Sep 22 15:18:31 rolyspi2 systemd[1]: systemd-rfkill.service: Succeeded. Sep 22 15:18:46 rolyspi2 bthelper[968]: Changing power off succeeded Sep 22 15:18:46 rolyspi2 bthelper[968]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Powered: no Sep 22 15:18:46 rolyspi2 bthelper[968]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Discovering: no Sep 22 15:18:46 rolyspi2 bthelper[968]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Class: 0x00000000 Sep 22 15:18:46 rolyspi2 bthelper[968]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Class: 0x000c0000 Sep 22 15:18:46 rolyspi2 bthelper[968]: Changing power on succeeded Sep 22 15:18:47 rolyspi2 kernel: [ 22.769227] v3d fec00000.v3d: MMU error from client L2T (0) at 0x3bc1000, pte invalid Sep 22 15:18:49 rolyspi2 pulseaudio[885]: E: [alsa-sink-bcm2835 HDMI 1] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write. Sep 22 15:18:49 rolyspi2 pulseaudio[885]: E: [alsa-sink-bcm2835 HDMI 1] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_bcm2835'. Please report this issue to the ALSA developers. Sep 22 15:18:49 rolyspi2 pulseaudio[885]: E: [alsa-sink-bcm2835 HDMI 1] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail. Sep 22 15:18:51 rolyspi2 signalk-server[384]: unable to check for new server version: FetchError: request to http://registry.npmjs.org/-/package/signalk-server/dist-tags failed, reason: getaddrinfo EAI_AGAIN registry.npmjs.org registry.npmjs.org:80 Sep 22 15:19:01 rolyspi2 systemd[1]: systemd-fsckd.service: Succeeded. Sep 22 15:19:11 rolyspi2 systemd[1]: systemd-hostnamed.service: Succeeded. Sep 22 15:19:13 rolyspi2 systemd[1]: openplotter-network.service: Succeeded. Sep 22 15:19:25 rolyspi2 kernel: [ 60.284345] usb 1-1.2: new high-speed USB device number 6 using xhci_hcd Sep 22 15:19:25 rolyspi2 kernel: [ 60.415350] usb 1-1.2: New USB device found, idVendor=04e8, idProduct=6860, bcdDevice= 4.19 Sep 22 15:19:25 rolyspi2 kernel: [ 60.415367] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 22 15:19:25 rolyspi2 kernel: [ 60.415381] usb 1-1.2: Product: SAMSUNG_Android Sep 22 15:19:25 rolyspi2 kernel: [ 60.415394] usb 1-1.2: Manufacturer: SAMSUNG Sep 22 15:19:25 rolyspi2 kernel: [ 60.415406] usb 1-1.2: SerialNumber: R58W30ZMK6N Sep 22 15:19:25 rolyspi2 kernel: [ 60.488604] cdc_acm 1-1.2:1.1: ttyACM0: USB ACM device Sep 22 15:19:25 rolyspi2 kernel: [ 60.488974] usbcore: registered new interface driver cdc_acm Sep 22 15:19:25 rolyspi2 kernel: [ 60.488981] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters Sep 22 15:19:25 rolyspi2 gvfsd[773]: Error 1: Get Storage information failed. Sep 22 15:19:26 rolyspi2 kernel: [ 61.354404] Under-voltage detected! (0x00050005) Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:27 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 kernel: [ 63.319343] usb 1-1.2: USB disconnect, device number 6 Sep 22 15:19:28 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:28 rolyspi2 kernel: [ 63.644330] usb 1-1.2: new high-speed USB device number 7 using xhci_hcd Sep 22 15:19:28 rolyspi2 kernel: [ 63.775179] usb 1-1.2: New USB device found, idVendor=04e8, idProduct=6860, bcdDevice= 4.19 Sep 22 15:19:28 rolyspi2 kernel: [ 63.775189] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 22 15:19:28 rolyspi2 kernel: [ 63.775197] usb 1-1.2: Product: SAMSUNG_Android Sep 22 15:19:28 rolyspi2 kernel: [ 63.775204] usb 1-1.2: Manufacturer: SAMSUNG Sep 22 15:19:28 rolyspi2 kernel: [ 63.775211] usb 1-1.2: SerialNumber: R58W30ZMK6N Sep 22 15:19:28 rolyspi2 kernel: [ 63.782186] cdc_acm 1-1.2:1.1: ttyACM0: USB ACM device Sep 22 15:19:29 rolyspi2 gvfsd[773]: Device 0 (VID=04e8 and PID=6860) is a Samsung Galaxy models (MTP). Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x01 occurred Sep 22 15:19:30 rolyspi2 gvfsd[773]: PTP: reading event an error 0x05 occurred Sep 22 15:19:30 rolyspi2 kernel: [ 66.135436] usb 1-1.2: USB disconnect, device number 7 Sep 22 15:19:31 rolyspi2 kernel: [ 66.434287] usb 1-1.2: new high-speed USB device number 8 using xhci_hcd Sep 22 15:19:31 rolyspi2 kernel: [ 66.565202] usb 1-1.2: New USB device found, idVendor=04e8, idProduct=6863, bcdDevice= 4.19 Sep 22 15:19:31 rolyspi2 kernel: [ 66.565236] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 22 15:19:31 rolyspi2 kernel: [ 66.565244] usb 1-1.2: Product: SAMSUNG_Android Sep 22 15:19:31 rolyspi2 kernel: [ 66.565250] usb 1-1.2: Manufacturer: SAMSUNG Sep 22 15:19:31 rolyspi2 kernel: [ 66.565257] usb 1-1.2: SerialNumber: R58W30ZMK6N Sep 22 15:19:31 rolyspi2 mtp-probe: checking bus 1, device 8: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2" Sep 22 15:19:31 rolyspi2 mtp-probe: bus: 1, device: 8 was not an MTP device Sep 22 15:19:31 rolyspi2 kernel: [ 66.597656] usbcore: registered new interface driver cdc_ether Sep 22 15:19:31 rolyspi2 kernel: [ 66.601854] rndis_host 1-1.2:1.0 usb0: register 'rndis_host' at usb-0000:01:00.0-1.2, RNDIS device, 22:02:b5:85:c4:90 Sep 22 15:19:31 rolyspi2 kernel: [ 66.602082] usbcore: registered new interface driver rndis_host Sep 22 15:19:31 rolyspi2 mtp-probe: checking bus 1, device 8: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2" Sep 22 15:19:31 rolyspi2 mtp-probe: bus: 1, device: 8 was not an MTP device Sep 22 15:19:31 rolyspi2 systemd-udevd[1319]: Using default interface naming scheme 'v240'. Sep 22 15:19:31 rolyspi2 avahi-daemon[439]: Joining mDNS multicast group on interface usb0.IPv4 with address 192.168.42.10. Sep 22 15:19:31 rolyspi2 avahi-daemon[439]: New relevant interface usb0.IPv4 for mDNS. Sep 22 15:19:31 rolyspi2 avahi-daemon[439]: Registering new address record for 192.168.42.10 on usb0.IPv4. Sep 22 15:19:31 rolyspi2 dhcpcd[484]: usb0: waiting for carrier Sep 22 15:19:31 rolyspi2 dhcpcd[484]: usb0: carrier acquired Sep 22 15:19:31 rolyspi2 gvfsd[773]: Device 0 (VID=04e8 and PID=6860) is a Samsung Galaxy models (MTP). Sep 22 15:19:32 rolyspi2 dhcpcd[484]: usb0: soliciting a DHCP lease Sep 22 15:19:33 rolyspi2 avahi-daemon[439]: Joining mDNS multicast group on interface usb0.IPv6 with address fe80::2002:b5ff:fe85:c490. Sep 22 15:19:33 rolyspi2 avahi-daemon[439]: New relevant interface usb0.IPv6 for mDNS. Sep 22 15:19:33 rolyspi2 avahi-daemon[439]: Registering new address record for fe80::2002:b5ff:fe85:c490 on usb0.*. Sep 22 15:19:37 rolyspi2 dhcpcd[484]: usb0: probing for an IPv4LL address Sep 22 15:19:41 rolyspi2 dhcpcd[484]: usb0: using IPv4LL address 169.254.86.219 Sep 22 15:19:41 rolyspi2 avahi-daemon[439]: Registering new address record for 169.254.86.219 on usb0.IPv4. Sep 22 15:19:41 rolyspi2 dhcpcd[484]: usb0: adding route to 169.254.0.0/16 Sep 22 15:21:35 rolyspi2 kernel: [ 190.314326] Voltage normalised (0x00000000) Sep 22 15:21:37 rolyspi2 kernel: [ 192.404409] Under-voltage detected! (0x00050005) Sep 22 15:26:01 rolyspi2 kernel: [ 456.554322] Voltage normalised (0x00000000) Sep 22 15:26:03 rolyspi2 kernel: [ 458.634436] Under-voltage detected! (0x00050005) Sep 22 15:27:33 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Activating service name='ca.desrt.dconf' requested by ':1.32' (uid=1000 pid=2502 comm="mousepad ") Sep 22 15:27:33 rolyspi2 dbus-daemon[732]: [session uid=1000 pid=732] Successfully activated service 'ca.desrt.dconf' Sep 22 15:27:39 rolyspi2 kernel: [ 554.314332] Voltage normalised (0x00000000) Sep 22 15:27:43 rolyspi2 kernel: [ 558.474623] Under-voltage detected! (0x00050005) Sep 22 15:27:48 rolyspi2 dbus-daemon[413]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.59' (uid=1000 pid=2502 comm="mousepad ") Sep 22 15:27:48 rolyspi2 systemd[1]: Starting Hostname Service... Sep 22 15:27:48 rolyspi2 dbus-daemon[413]: [system] Successfully activated service 'org.freedesktop.hostname1' Sep 22 15:27:48 rolyspi2 systemd[1]: Started Hostname Service. Sep 22 15:27:49 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:27:49 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:27:50 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:27:50 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:27:51 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:27:51 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:01 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:01 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:02 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:02 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:03 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:03 rolyspi2 gvfsd[773]: mkdir failed on directory /var/cache/samba: Permission denied Sep 22 15:28:18 rolyspi2 systemd[1]: systemd-hostnamed.service: Succeeded. Sep 22 15:29:00 rolyspi2 kernel: [ 635.434312] Voltage normalised (0x00000000) Sep 22 15:29:06 rolyspi2 kernel: [ 641.674483] Under-voltage detected! (0x00050005) Sep 22 15:29:12 rolyspi2 kernel: [ 647.914320] Voltage normalised (0x00000000) Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping RealtimeKit Scheduling Policy Service... Sep 22 15:29:44 rolyspi2 systemd[1]: Unmounting RPC Pipe File System... Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped target Timers. Sep 22 15:29:44 rolyspi2 systemd[1]: apt-daily-upgrade.timer: Succeeded. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped Daily apt upgrade and clean activities. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped target Sound Card. Sep 22 15:29:44 rolyspi2 systemd[1]: Condition check resulted in Turns off Raspberry Pi display backlight on shutdown/reboot being skipped. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping Authorization Manager... Sep 22 15:29:44 rolyspi2 systemd[1]: logrotate.timer: Succeeded. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped Daily rotation of log files. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped target Bluetooth. Sep 22 15:29:44 rolyspi2 bluetoothd[980]: Terminating Sep 22 15:29:44 rolyspi2 bluetoothd[980]: Endpoint unregistered: sender=:1.26 path=/MediaEndpoint/A2DPSource Sep 22 15:29:44 rolyspi2 bluetoothd[980]: Endpoint unregistered: sender=:1.26 path=/MediaEndpoint/A2DPSink Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping Bluetooth service... Sep 22 15:29:44 rolyspi2 systemd[1]: systemd-rfkill.socket: Succeeded. Sep 22 15:29:44 rolyspi2 systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch. Sep 22 15:29:44 rolyspi2 systemd[1]: systemd-tmpfiles-clean.timer: Succeeded. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped Daily Cleanup of Temporary Directories. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping Session 1 of user pi. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping Session 3 of user pi. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped target Graphical Interface. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped target Multi-User System. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping Make remote CUPS printers available locally... Sep 22 15:29:44 rolyspi2 bluetoothd[980]: Stopping SDP server Sep 22 15:29:44 rolyspi2 bluetoothd[980]: Exit Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping dphys-swapfile - set up, mount/unmount, and delete a swap file... Sep 22 15:29:44 rolyspi2 systemd[1]: rpi-eeprom-update.service: Succeeded. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopped Check for Raspberry Pi EEPROM updates. Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping signalk.service... Sep 22 15:29:44 rolyspi2 systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Sep 22 15:29:51 rolyspi2 fake-hwclock[125]: Fri 22 Sep 05:29:47 UTC 2023 Sep 22 15:29:51 rolyspi2 systemd-fsck[141]: e2fsck 1.44.5 (15-Dec-2018) Sep 22 15:29:51 rolyspi2 systemd-fsck[141]: rootfs: clean, 193950/1933312 files, 2219671/7725184 blocks Sep 22 15:29:51 rolyspi2 systemd[1]: Started Set the console keyboard layout. Sep 22 15:29:51 rolyspi2 systemd[1]: Started udev Coldplug all Devices. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Remount Root and Kernel File Systems. Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Create System Users... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Flush Journal to Persistent Storage... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Load/Save Random Seed... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Create System Users. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Flush Journal to Persistent Storage. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Load/Save Random Seed. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Create Static Device Nodes in /dev... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Create Static Device Nodes in /dev. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting udev Kernel Device Manager... Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Local File Systems (Pre). Sep 22 15:29:51 rolyspi2 systemd[1]: Started udev Kernel Device Manager. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Show Plymouth Boot Screen... Sep 22 15:29:51 rolyspi2 systemd[1]: Received SIGRTMIN+20 from PID 171 (plymouthd). Sep 22 15:29:51 rolyspi2 systemd[1]: Started Show Plymouth Boot Screen. Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Local Encrypted Volumes. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Sep 22 15:29:51 rolyspi2 mtp-probe: checking bus 1, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4" Sep 22 15:29:51 rolyspi2 mtp-probe: bus: 1, device: 6 was not an MTP device Sep 22 15:29:51 rolyspi2 mtp-probe: checking bus 1, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4" Sep 22 15:29:51 rolyspi2 mtp-probe: bus: 1, device: 6 was not an MTP device Sep 22 15:29:51 rolyspi2 systemd[1]: Found device /dev/disk/by-partuuid/389d8ea4-01. Sep 22 15:29:51 rolyspi2 systemd-udevd[194]: Using default interface naming scheme 'v240'. Sep 22 15:29:51 rolyspi2 mtp-probe: checking bus 1, device 3: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1" Sep 22 15:29:51 rolyspi2 mtp-probe: bus: 1, device: 3 was not an MTP device Sep 22 15:29:51 rolyspi2 mtp-probe: checking bus 1, device 6: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4" Sep 22 15:29:51 rolyspi2 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3" Sep 22 15:29:51 rolyspi2 mtp-probe: bus: 1, device: 5 was not an MTP device Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Booting Linux on physical CPU 0x0 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Linux version 5.10.103-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) #1529 SMP Tue Mar 8 12:24:00 GMT 2022 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] CPU: div instructions available: patching division code Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.4 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] random: fast init done Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Memory policy: Data cache writealloc Sep 22 15:29:51 rolyspi2 mtp-probe: bus: 1, device: 6 was not an MTP device Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Reserved memory: created CMA memory pool at 0x000000001ac00000, size 320 MiB Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Zone ranges: Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] DMA [mem 0x0000000000000000-0x000000002fffffff] Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Normal empty Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] HighMem [mem 0x0000000030000000-0x00000001ffffffff] Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Movable zone start for each node Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Early memory node ranges Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] node 0: [mem 0x0000000000000000-0x000000002fffffff] Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] node 0: [mem 0x0000000100000000-0x00000001ffffffff] Sep 22 15:29:51 rolyspi2 systemd[1]: Starting File System Check on /dev/disk/by-partuuid/389d8ea4-01... Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] On node 0 totalpages: 2015232 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] DMA zone: 1728 pages used for memmap Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Load/Save RF Kill Switch Status... Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] DMA zone: 0 pages reserved Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] DMA zone: 196608 pages, LIFO batch:63 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] HighMem zone: 1818624 pages, LIFO batch:63 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] pcpu-alloc: s50828 r8192 d22900 u81920 alloc=20*4096 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Sep 22 15:29:51 rolyspi2 systemd-udevd[175]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2013504 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60D,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 smsc95xx.macaddr=DC:A6:32:E0:C8:43 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=tty1 root=PARTUUID=389d8ea4-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles Sep 22 15:29:51 rolyspi2 systemd-udevd[189]: Using default interface naming scheme 'v240'. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Kernel parameter elevator= does not have any effect anymore. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Please use sysfs to set IO scheduler for individual devices. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] software IO TLB: mapped [mem 0x0000000012400000-0x0000000016400000] (64MB) Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Memory: 7575876K/8060928K available (10240K kernel code, 1366K rwdata, 3196K rodata, 2048K init, 882K bss, 157372K reserved, 327680K cma-reserved, 7274496K highmem) Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] ftrace: allocating 34355 entries in 101 pages Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] ftrace: allocated 101 pages with 4 groups Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] rcu: Hierarchical RCU implementation. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Rude variant of Tasks RCU enabled. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] Tracing variant of Tasks RCU enabled. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] GIC: Using split EOI/Deactivate mode Sep 22 15:29:51 rolyspi2 kernel: [ 0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1 Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in FUSE Control File System being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000009] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns Sep 22 15:29:51 rolyspi2 kernel: [ 0.000027] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns Sep 22 15:29:51 rolyspi2 kernel: [ 0.000085] bcm2835: system timer (irq = 25) Sep 22 15:29:51 rolyspi2 kernel: [ 0.000740] arch_timer: cp15 timer(s) running at 54.00MHz (phys). Sep 22 15:29:51 rolyspi2 kernel: [ 0.000757] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 0.000776] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Sep 22 15:29:51 rolyspi2 kernel: [ 0.000790] Switching to timer-based delay loop, resolution 18ns Sep 22 15:29:51 rolyspi2 kernel: [ 0.001042] Console: colour dummy device 80x30 Sep 22 15:29:51 rolyspi2 kernel: [ 0.001109] printk: console [tty1] enabled Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 0.001165] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) Sep 22 15:29:51 rolyspi2 kernel: [ 0.001198] pid_max: default: 32768 minimum: 301 Sep 22 15:29:51 rolyspi2 kernel: [ 0.001362] LSM: Security Framework initializing Sep 22 15:29:51 rolyspi2 kernel: [ 0.001547] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Sep 22 15:29:51 rolyspi2 systemd[1]: Started Load/Save RF Kill Switch Status. Sep 22 15:29:51 rolyspi2 kernel: [ 0.001572] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 0.003037] cgroup: Disabling memory control group subsystem Sep 22 15:29:51 rolyspi2 kernel: [ 0.003267] CPU: Testing write buffer coherency: ok Sep 22 15:29:51 rolyspi2 kernel: [ 0.003717] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Sep 22 15:29:51 rolyspi2 kernel: [ 0.004905] Setting up static identity map for 0x200000 - 0x20003c Sep 22 15:29:51 rolyspi2 kernel: [ 0.005099] rcu: Hierarchical SRCU implementation. Sep 22 15:29:51 rolyspi2 systemd-udevd[180]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:29:51 rolyspi2 kernel: [ 0.006016] smp: Bringing up secondary CPUs ... Sep 22 15:29:51 rolyspi2 kernel: [ 0.007195] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Sep 22 15:29:51 rolyspi2 kernel: [ 0.008527] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Sep 22 15:29:51 rolyspi2 systemd-udevd[198]: Using default interface naming scheme 'v240'. Sep 22 15:29:51 rolyspi2 kernel: [ 0.009793] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Sep 22 15:29:51 rolyspi2 kernel: [ 0.009950] smp: Brought up 1 node, 4 CPUs Sep 22 15:29:51 rolyspi2 kernel: [ 0.009971] SMP: Total of 4 processors activated (432.00 BogoMIPS). Sep 22 15:29:51 rolyspi2 kernel: [ 0.009986] CPU: All CPU(s) started in HYP mode. Sep 22 15:29:51 rolyspi2 kernel: [ 0.010000] CPU: Virtualization extensions available. Sep 22 15:29:51 rolyspi2 kernel: [ 0.010805] devtmpfs: initialized Sep 22 15:29:51 rolyspi2 systemd-fsck[323]: fsck.fat 4.1 (2017-01-24) Sep 22 15:29:51 rolyspi2 kernel: [ 0.025276] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Sep 22 15:29:51 rolyspi2 kernel: [ 0.025496] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Sep 22 15:29:51 rolyspi2 kernel: [ 0.025526] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 0.033738] pinctrl core: initialized pinctrl subsystem Sep 22 15:29:51 rolyspi2 kernel: [ 0.034828] NET: Registered protocol family 16 Sep 22 15:29:51 rolyspi2 systemd-fsck[323]: /dev/mmcblk0p1: 292 files, 98800/516190 clusters Sep 22 15:29:51 rolyspi2 kernel: [ 0.038565] DMA: preallocated 1024 KiB pool for atomic coherent allocations Sep 22 15:29:51 rolyspi2 kernel: [ 0.039328] audit: initializing netlink subsys (disabled) Sep 22 15:29:51 rolyspi2 kernel: [ 0.039590] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 Sep 22 15:29:51 rolyspi2 kernel: [ 0.040163] thermal_sys: Registered thermal governor 'step_wise' Sep 22 15:29:51 rolyspi2 kernel: [ 0.041054] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Sep 22 15:29:51 rolyspi2 systemd[1]: Started File System Check on /dev/disk/by-partuuid/389d8ea4-01. Sep 22 15:29:51 rolyspi2 kernel: [ 0.041071] hw-breakpoint: maximum watchpoint size is 8 bytes. Sep 22 15:29:51 rolyspi2 kernel: [ 0.041483] Serial: AMBA PL011 UART driver Sep 22 15:29:51 rolyspi2 kernel: [ 0.077276] bcm2835-mbox fe00b880.mailbox: mailbox enabled Sep 22 15:29:51 rolyspi2 kernel: [ 0.090840] raspberrypi-firmware soc:firmware: Attached to firmware from 2023-05-09T12:16:34, variant start Sep 22 15:29:51 rolyspi2 systemd-udevd[169]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:29:51 rolyspi2 kernel: [ 0.100854] raspberrypi-firmware soc:firmware: Firmware hash is 30aa0d70ab280427ba04ebc718c81d4350b9d394 Sep 22 15:29:51 rolyspi2 kernel: [ 0.141253] Kprobes globally optimized Sep 22 15:29:51 rolyspi2 kernel: [ 0.146789] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Sep 22 15:29:51 rolyspi2 systemd-udevd[177]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:29:51 rolyspi2 kernel: [ 0.151012] vgaarb: loaded Sep 22 15:29:51 rolyspi2 kernel: [ 0.151454] SCSI subsystem initialized Sep 22 15:29:51 rolyspi2 kernel: [ 0.151679] usbcore: registered new interface driver usbfs Sep 22 15:29:51 rolyspi2 kernel: [ 0.151739] usbcore: registered new interface driver hub Sep 22 15:29:51 rolyspi2 kernel: [ 0.151822] usbcore: registered new device driver usb Sep 22 15:29:51 rolyspi2 kernel: [ 0.152182] usb_phy_generic phy: supply vcc not found, using dummy regulator Sep 22 15:29:51 rolyspi2 systemd[1]: Mounting /boot... Sep 22 15:29:51 rolyspi2 kernel: [ 0.154161] clocksource: Switched to clocksource arch_sys_counter Sep 22 15:29:51 rolyspi2 kernel: [ 1.099946] VFS: Disk quotas dquot_6.6.0 Sep 22 15:29:51 rolyspi2 kernel: [ 1.100037] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Sep 22 15:29:51 rolyspi2 systemd-udevd[176]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:29:51 rolyspi2 kernel: [ 1.100200] FS-Cache: Loaded Sep 22 15:29:51 rolyspi2 kernel: [ 1.100399] CacheFiles: Loaded Sep 22 15:29:51 rolyspi2 kernel: [ 1.101441] simple-framebuffer 3e513000.framebuffer: framebuffer at 0x3e513000, 0x6e7000 bytes, mapped to 0x(ptrval) Sep 22 15:29:51 rolyspi2 kernel: [ 1.101462] simple-framebuffer 3e513000.framebuffer: format=a8r8g8b8, mode=1824x984x32, linelength=7296 Sep 22 15:29:51 rolyspi2 kernel: [ 1.101941] Console: switching to colour frame buffer device 228x61 Sep 22 15:29:51 rolyspi2 systemd-udevd[165]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 22 15:29:51 rolyspi2 systemd[1]: Mounted /boot. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Local File Systems. Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Create Volatile Files and Directories... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Preprocess NFS configuration... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Set console font and keymap... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Sep 22 15:29:51 rolyspi2 systemd[1]: nfs-config.service: Succeeded. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Preprocess NFS configuration. Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target NFS client services. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Remote File Systems (Pre). Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Remote File Systems. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Set console font and keymap. Sep 22 15:29:51 rolyspi2 kernel: [ 1.110620] simple-framebuffer 3e513000.framebuffer: fb0: simplefb registered! Sep 22 15:29:51 rolyspi2 kernel: [ 1.120817] NET: Registered protocol family 2 Sep 22 15:29:51 rolyspi2 kernel: [ 1.121034] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 1.122519] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 1.122561] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 1.122625] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 1.122693] TCP: Hash tables configured (established 8192 bind 8192) Sep 22 15:29:51 rolyspi2 kernel: [ 1.122845] UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 1.122879] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Sep 22 15:29:51 rolyspi2 kernel: [ 1.123109] NET: Registered protocol family 1 Sep 22 15:29:51 rolyspi2 kernel: [ 1.124245] RPC: Registered named UNIX socket transport module. Sep 22 15:29:51 rolyspi2 kernel: [ 1.124261] RPC: Registered udp transport module. Sep 22 15:29:51 rolyspi2 kernel: [ 1.124277] RPC: Registered tcp transport module. Sep 22 15:29:51 rolyspi2 kernel: [ 1.124292] RPC: Registered tcp NFSv4.1 backchannel transport module. Sep 22 15:29:51 rolyspi2 kernel: [ 1.124316] PCI: CLS 0 bytes, default 64 Sep 22 15:29:51 rolyspi2 kernel: [ 1.127387] Initialise system trusted keyrings Sep 22 15:29:51 rolyspi2 kernel: [ 1.127629] workingset: timestamp_bits=14 max_order=21 bucket_order=7 Sep 22 15:29:51 rolyspi2 kernel: [ 1.135986] zbud: loaded Sep 22 15:29:51 rolyspi2 kernel: [ 1.137780] FS-Cache: Netfs 'nfs' registered for caching Sep 22 15:29:51 rolyspi2 kernel: [ 1.138545] NFS: Registering the id_resolver key type Sep 22 15:29:51 rolyspi2 kernel: [ 1.138617] Key type id_resolver registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.138632] Key type id_legacy registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.138757] nfs4filelayout_init: NFSv4 File Layout Driver Registering... Sep 22 15:29:51 rolyspi2 kernel: [ 1.138773] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Sep 22 15:29:51 rolyspi2 kernel: [ 1.139795] Key type asymmetric registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.139811] Asymmetric key parser 'x509' registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.140006] bounce: pool size: 64 pages Sep 22 15:29:51 rolyspi2 kernel: [ 1.140049] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) Sep 22 15:29:51 rolyspi2 kernel: [ 1.140269] io scheduler mq-deadline registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.140286] io scheduler kyber registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.144812] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Sep 22 15:29:51 rolyspi2 kernel: [ 1.144844] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Sep 22 15:29:51 rolyspi2 kernel: [ 1.144924] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Sep 22 15:29:51 rolyspi2 kernel: [ 1.145013] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 Sep 22 15:29:51 rolyspi2 kernel: [ 1.206258] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Sep 22 15:29:51 rolyspi2 kernel: [ 1.206644] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Sep 22 15:29:51 rolyspi2 kernel: [ 1.206665] pci_bus 0000:00: root bus resource [bus 00-ff] Sep 22 15:29:51 rolyspi2 kernel: [ 1.206687] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Sep 22 15:29:51 rolyspi2 kernel: [ 1.206777] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Sep 22 15:29:51 rolyspi2 kernel: [ 1.207019] pci 0000:00:00.0: PME# supported from D0 D3hot Sep 22 15:29:51 rolyspi2 kernel: [ 1.210608] PCI: bus0: Fast back to back transfers disabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.210980] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Sep 22 15:29:51 rolyspi2 kernel: [ 1.211105] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Sep 22 15:29:51 rolyspi2 kernel: [ 1.211539] pci 0000:01:00.0: PME# supported from D0 D3hot Sep 22 15:29:51 rolyspi2 kernel: [ 1.215145] PCI: bus1: Fast back to back transfers disabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.215237] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Sep 22 15:29:51 rolyspi2 systemd[1]: Started Create Volatile Files and Directories. Sep 22 15:29:51 rolyspi2 kernel: [ 1.215262] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Sep 22 15:29:51 rolyspi2 kernel: [ 1.215344] pci 0000:00:00.0: PCI bridge to [bus 01] Sep 22 15:29:51 rolyspi2 kernel: [ 1.215369] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Sep 22 15:29:51 rolyspi2 kernel: [ 1.215775] pcieport 0000:00:00.0: enabling device (0140 -> 0142) Sep 22 15:29:51 rolyspi2 kernel: [ 1.215991] pcieport 0000:00:00.0: PME: Signaling with IRQ 66 Sep 22 15:29:51 rolyspi2 kernel: [ 1.222179] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.223080] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default Sep 22 15:29:51 rolyspi2 kernel: [ 1.225711] iproc-rng200 fe104000.rng: hwrng registered Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Network Time Synchronization... Sep 22 15:29:51 rolyspi2 kernel: [ 1.226028] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Sep 22 15:29:51 rolyspi2 kernel: [ 1.226917] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 Sep 22 15:29:51 rolyspi2 kernel: [ 1.238913] brd: module loaded Sep 22 15:29:51 rolyspi2 kernel: [ 1.251074] loop: module loaded Sep 22 15:29:51 rolyspi2 kernel: [ 1.252824] Loading iSCSI transport class v2.0-870. Sep 22 15:29:51 rolyspi2 kernel: [ 1.257771] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Sep 22 15:29:51 rolyspi2 kernel: [ 1.354324] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Sep 22 15:29:51 rolyspi2 kernel: [ 1.355515] usbcore: registered new interface driver r8152 Sep 22 15:29:51 rolyspi2 kernel: [ 1.355584] usbcore: registered new interface driver lan78xx Sep 22 15:29:51 rolyspi2 kernel: [ 1.355644] usbcore: registered new interface driver smsc95xx Sep 22 15:29:51 rolyspi2 kernel: [ 1.401796] xhci_hcd 0000:01:00.0: xHCI Host Controller Sep 22 15:29:51 rolyspi2 systemd[1]: Received SIGRTMIN+20 from PID 171 (plymouthd). Sep 22 15:29:51 rolyspi2 kernel: [ 1.401832] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Sep 22 15:29:51 rolyspi2 kernel: [ 1.405063] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000060000000890 Sep 22 15:29:51 rolyspi2 kernel: [ 1.406380] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 Sep 22 15:29:51 rolyspi2 systemd[1]: plymouth-read-write.service: Succeeded. Sep 22 15:29:51 rolyspi2 kernel: [ 1.406400] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 22 15:29:51 rolyspi2 kernel: [ 1.406417] usb usb1: Product: xHCI Host Controller Sep 22 15:29:51 rolyspi2 kernel: [ 1.406433] usb usb1: Manufacturer: Linux 5.10.103-v7l+ xhci-hcd Sep 22 15:29:51 rolyspi2 kernel: [ 1.406449] usb usb1: SerialNumber: 0000:01:00.0 Sep 22 15:29:51 rolyspi2 kernel: [ 1.407198] hub 1-0:1.0: USB hub found Sep 22 15:29:51 rolyspi2 kernel: [ 1.407299] hub 1-0:1.0: 1 port detected Sep 22 15:29:51 rolyspi2 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Sep 22 15:29:51 rolyspi2 kernel: [ 1.407977] xhci_hcd 0000:01:00.0: xHCI Host Controller Sep 22 15:29:51 rolyspi2 kernel: [ 1.408005] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Sep 22 15:29:51 rolyspi2 kernel: [ 1.408030] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Sep 22 15:29:51 rolyspi2 kernel: [ 1.408526] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 Sep 22 15:29:51 rolyspi2 kernel: [ 1.408545] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 22 15:29:51 rolyspi2 kernel: [ 1.408563] usb usb2: Product: xHCI Host Controller Sep 22 15:29:51 rolyspi2 kernel: [ 1.408579] usb usb2: Manufacturer: Linux 5.10.103-v7l+ xhci-hcd Sep 22 15:29:51 rolyspi2 kernel: [ 1.408596] usb usb2: SerialNumber: 0000:01:00.0 Sep 22 15:29:51 rolyspi2 systemd[1]: Started Update UTMP about System Boot/Shutdown. Sep 22 15:29:51 rolyspi2 kernel: [ 1.409304] hub 2-0:1.0: USB hub found Sep 22 15:29:51 rolyspi2 kernel: [ 1.409378] hub 2-0:1.0: 4 ports detected Sep 22 15:29:51 rolyspi2 systemd[1]: Started Network Time Synchronization. Sep 22 15:29:51 rolyspi2 kernel: [ 1.411087] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Sep 22 15:29:51 rolyspi2 kernel: [ 1.411425] dwc_otg: FIQ enabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.411440] dwc_otg: NAK holdoff enabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.411455] dwc_otg: FIQ split-transaction FSM enabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.411472] Module dwc_common_port init Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target System Time Synchronized. Sep 22 15:29:51 rolyspi2 kernel: [ 1.411915] usbcore: registered new interface driver uas Sep 22 15:29:51 rolyspi2 kernel: [ 1.412023] usbcore: registered new interface driver usb-storage Sep 22 15:29:51 rolyspi2 kernel: [ 1.412234] mousedev: PS/2 mouse device common for all mice Sep 22 15:29:51 rolyspi2 kernel: [ 1.413973] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target System Initialization. Sep 22 15:29:51 rolyspi2 kernel: [ 1.417348] sdhci: Secure Digital Host Controller Interface driver Sep 22 15:29:51 rolyspi2 kernel: [ 1.417363] sdhci: Copyright(c) Pierre Ossman Sep 22 15:29:51 rolyspi2 kernel: [ 1.418094] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe Sep 22 15:29:51 rolyspi2 kernel: [ 1.418773] sdhci-pltfm: SDHCI platform and OF driver helper Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on signalk.socket. Sep 22 15:29:51 rolyspi2 kernel: [ 1.422891] ledtrig-cpu: registered to indicate activity on CPUs Sep 22 15:29:51 rolyspi2 kernel: [ 1.423250] hid: raw HID events driver (C) Jiri Kosina Sep 22 15:29:51 rolyspi2 kernel: [ 1.423433] usbcore: registered new interface driver usbhid Sep 22 15:29:51 rolyspi2 kernel: [ 1.423448] usbhid: USB HID core driver Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on GPS (Global Positioning System) Daemon Sockets. Sep 22 15:29:51 rolyspi2 kernel: [ 1.428872] Initializing XFRM netlink socket Sep 22 15:29:51 rolyspi2 kernel: [ 1.428914] NET: Registered protocol family 17 Sep 22 15:29:51 rolyspi2 kernel: [ 1.429038] Key type dns_resolver registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.429491] Registering SWP/SWPB emulation handler Sep 22 15:29:51 rolyspi2 kernel: [ 1.429676] registered taskstats version 1 Sep 22 15:29:51 rolyspi2 systemd[1]: Started Daily apt download activities. Sep 22 15:29:51 rolyspi2 kernel: [ 1.429704] Loading compiled-in X.509 certificates Sep 22 15:29:51 rolyspi2 kernel: [ 1.430549] Key type ._fscrypt registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.430566] Key type .fscrypt registered Sep 22 15:29:51 rolyspi2 systemd[1]: Started Daily Cleanup of Temporary Directories. Sep 22 15:29:51 rolyspi2 kernel: [ 1.430581] Key type fscrypt-provisioning registered Sep 22 15:29:51 rolyspi2 kernel: [ 1.442150] uart-pl011 fe201000.serial: there is not valid maps for state default Sep 22 15:29:51 rolyspi2 kernel: [ 1.442466] uart-pl011 fe201000.serial: cts_event_workaround enabled Sep 22 15:29:51 rolyspi2 kernel: [ 1.442540] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2 Sep 22 15:29:51 rolyspi2 kernel: [ 1.449304] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default Sep 22 15:29:51 rolyspi2 kernel: [ 1.450193] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 38, base_baud = 62500000) is a 16550 Sep 22 15:29:51 rolyspi2 systemd[1]: Started CUPS Scheduler. Sep 22 15:29:51 rolyspi2 kernel: [ 1.451179] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Sep 22 15:29:51 rolyspi2 kernel: [ 1.452231] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Paths. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Daily rotation of log files. Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on CUPS Scheduler. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Daily apt upgrade and clean activities. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Daily man-db regeneration. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Timers. Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on D-Bus System Message Bus Socket. Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Sep 22 15:29:51 rolyspi2 systemd[1]: Listening on triggerhappy.socket. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Sockets. Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Basic System. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting rng-tools.service... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Check for v3d driver... Sep 22 15:29:51 rolyspi2 systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)... Sep 22 15:29:51 rolyspi2 rngd[392]: rngd 2-unofficial-mt.14 starting up... Sep 22 15:29:51 rolyspi2 rng-tools[380]: Starting Hardware RNG entropy gatherer daemon: rngd. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Login Service... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Regular background program processing daemon. Sep 22 15:29:51 rolyspi2 systemd[1]: Started D-Bus System Message Bus. Sep 22 15:29:51 rolyspi2 cron[396]: (CRON) INFO (pidfile fd = 3) Sep 22 15:29:51 rolyspi2 rngd[392]: entropy feed to the kernel ready Sep 22 15:29:51 rolyspi2 cron[396]: (CRON) INFO (Running @reboot jobs) Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 1.452248] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Sep 22 15:29:51 rolyspi2 kernel: [ 1.481626] of_cfs_init Sep 22 15:29:51 rolyspi2 kernel: [ 1.481891] of_cfs_init: OK Sep 22 15:29:51 rolyspi2 kernel: [ 1.504329] mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Sep 22 15:29:51 rolyspi2 kernel: [ 1.506019] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Sep 22 15:29:51 rolyspi2 kernel: [ 1.507703] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Sep 22 15:29:51 rolyspi2 systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Sep 22 15:29:51 rolyspi2 kernel: [ 1.510723] mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Sep 22 15:29:51 rolyspi2 kernel: [ 1.512407] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Sep 22 15:29:51 rolyspi2 kernel: [ 1.520477] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 1.521132] Waiting for root device PARTUUID=389d8ea4-02... Sep 22 15:29:51 rolyspi2 kernel: [ 1.594257] mmc1: new high speed SDIO card at address 0001 Sep 22 15:29:51 rolyspi2 kernel: [ 1.627683] mmc0: new ultra high speed DDR50 SDHC card at address aaaa Sep 22 15:29:51 rolyspi2 kernel: [ 1.628516] mmcblk0: mmc0:aaaa SC32G 29.7 GiB Sep 22 15:29:51 rolyspi2 kernel: [ 1.631171] mmcblk0: p1 p2 Sep 22 15:29:51 rolyspi2 kernel: [ 1.654434] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Sep 22 15:29:51 rolyspi2 kernel: [ 1.654520] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting dhcpcd on all interfaces... Sep 22 15:29:51 rolyspi2 kernel: [ 1.662011] devtmpfs: mounted Sep 22 15:29:51 rolyspi2 kernel: [ 1.672117] Freeing unused kernel memory: 2048K Sep 22 15:29:51 rolyspi2 kernel: [ 1.704236] usb 1-1: new high-speed USB device number 2 using xhci_hcd Sep 22 15:29:51 rolyspi2 kernel: [ 1.714497] Run /sbin/init as init process Sep 22 15:29:51 rolyspi2 kernel: [ 1.714512] with arguments: Sep 22 15:29:51 rolyspi2 kernel: [ 1.714527] /sbin/init Sep 22 15:29:51 rolyspi2 kernel: [ 1.714541] splash Sep 22 15:29:51 rolyspi2 kernel: [ 1.714555] with environment: Sep 22 15:29:51 rolyspi2 kernel: [ 1.714569] HOME=/ Sep 22 15:29:51 rolyspi2 systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped. Sep 22 15:29:51 rolyspi2 kernel: [ 1.714584] TERM=linux Sep 22 15:29:51 rolyspi2 kernel: [ 1.896852] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Sep 22 15:29:51 rolyspi2 kernel: [ 1.896874] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Sep 22 15:29:51 rolyspi2 kernel: [ 1.896891] usb 1-1: Product: USB2.0 Hub Sep 22 15:29:51 rolyspi2 kernel: [ 1.899372] hub 1-1:1.0: USB hub found Sep 22 15:29:51 rolyspi2 kernel: [ 1.899670] hub 1-1:1.0: 4 ports detected Sep 22 15:29:51 rolyspi2 kernel: [ 2.224553] usb 1-1.1: new full-speed USB device number 3 using xhci_hcd Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Check for Raspberry Pi EEPROM updates... Sep 22 15:29:51 rolyspi2 kernel: [ 2.256469] NET: Registered protocol family 10 Sep 22 15:29:51 rolyspi2 kernel: [ 2.257895] Segment Routing with IPv6 Sep 22 15:29:51 rolyspi2 kernel: [ 2.368723] usb 1-1.1: New USB device found, idVendor=1547, idProduct=1000, bcdDevice= 0.01 Sep 22 15:29:51 rolyspi2 kernel: [ 2.368743] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 22 15:29:51 rolyspi2 kernel: [ 2.368760] usb 1-1.1: Product: SG-Lock USB Key Sep 22 15:29:51 rolyspi2 kernel: [ 2.368776] usb 1-1.1: Manufacturer: SG-Lock Sep 22 15:29:51 rolyspi2 kernel: [ 2.376067] hid-generic 0003:1547:1000.0001: hiddev96,hidraw0: USB HID v1.00 Device [SG-Lock SG-Lock USB Key] on usb-0000:01:00.0-1.1/input0 Sep 22 15:29:51 rolyspi2 kernel: [ 2.484294] usb 1-1.2: new high-speed USB device number 4 using xhci_hcd Sep 22 15:29:51 rolyspi2 kernel: [ 2.615951] usb 1-1.2: New USB device found, idVendor=04e8, idProduct=6860, bcdDevice= 4.19 Sep 22 15:29:51 rolyspi2 kernel: [ 2.615974] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 22 15:29:51 rolyspi2 kernel: [ 2.615992] usb 1-1.2: Product: SAMSUNG_Android Sep 22 15:29:51 rolyspi2 kernel: [ 2.616009] usb 1-1.2: Manufacturer: SAMSUNG Sep 22 15:29:51 rolyspi2 kernel: [ 2.616025] usb 1-1.2: SerialNumber: R58W30ZMK6N Sep 22 15:29:51 rolyspi2 kernel: [ 2.734219] usb 1-1.3: new low-speed USB device number 5 using xhci_hcd Sep 22 15:29:51 rolyspi2 kernel: [ 2.902691] usb 1-1.3: New USB device found, idVendor=0e8f, idProduct=00a8, bcdDevice= 3.11 Sep 22 15:29:51 rolyspi2 kernel: [ 2.902713] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 22 15:29:51 rolyspi2 systemd[1]: Started openplotter-network.service. Sep 22 15:29:51 rolyspi2 kernel: [ 2.902731] usb 1-1.3: Product: 2.4G RX Sep 22 15:29:51 rolyspi2 kernel: [ 2.902748] usb 1-1.3: Manufacturer: DaKai Sep 22 15:29:51 rolyspi2 systemd[1]: Started signalk.service. Sep 22 15:29:51 rolyspi2 kernel: [ 2.914337] input: DaKai 2.4G RX as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/0003:0E8F:00A8.0002/input/input0 Sep 22 15:29:51 rolyspi2 kernel: [ 2.984930] hid-generic 0003:0E8F:00A8.0002: input,hidraw1: USB HID v1.10 Keyboard [DaKai 2.4G RX] on usb-0000:01:00.0-1.3/input0 Sep 22 15:29:51 rolyspi2 kernel: [ 2.997439] input: DaKai 2.4G RX Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input1 Sep 22 15:29:51 rolyspi2 kernel: [ 2.997919] input: DaKai 2.4G RX System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input2 Sep 22 15:29:51 rolyspi2 kernel: [ 3.064655] input: DaKai 2.4G RX Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input3 Sep 22 15:29:51 rolyspi2 kernel: [ 3.065039] input: DaKai 2.4G RX as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:0E8F:00A8.0003/input/input4 Sep 22 15:29:51 rolyspi2 dhcpcd[402]: dev: loaded udev Sep 22 15:29:51 rolyspi2 kernel: [ 3.065455] hid-generic 0003:0E8F:00A8.0003: input,hiddev97,hidraw2: USB HID v1.10 Mouse [DaKai 2.4G RX] on usb-0000:01:00.0-1.3/input1 Sep 22 15:29:51 rolyspi2 kernel: [ 3.107194] random: systemd: uninitialized urandom read (16 bytes read) Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Sep 22 15:29:51 rolyspi2 kernel: [ 3.120975] random: systemd: uninitialized urandom read (16 bytes read) Sep 22 15:29:51 rolyspi2 kernel: [ 3.122238] random: systemd: uninitialized urandom read (16 bytes read) Sep 22 15:29:51 rolyspi2 kernel: [ 3.164323] usb 1-1.4: new full-speed USB device number 6 using xhci_hcd Sep 22 15:29:51 rolyspi2 kernel: [ 3.302754] usb 1-1.4: New USB device found, idVendor=067b, idProduct=2303, bcdDevice= 4.00 Sep 22 15:29:51 rolyspi2 kernel: [ 3.302779] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 22 15:29:51 rolyspi2 kernel: [ 3.302798] usb 1-1.4: Product: USB-Serial Controller D Sep 22 15:29:51 rolyspi2 systemd[1]: Starting System Logging Service... Sep 22 15:29:51 rolyspi2 kernel: [ 3.302815] usb 1-1.4: Manufacturer: Prolific Technology Inc. Sep 22 15:29:51 rolyspi2 kernel: [ 3.859552] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null) Sep 22 15:29:51 rolyspi2 rfkill: unblock set for all Sep 22 15:29:51 rolyspi2 kernel: [ 4.637018] usbcore: registered new interface driver usbserial_generic Sep 22 15:29:51 rolyspi2 kernel: [ 4.638283] gpio-fan gpio-fan@0: GPIO fan initialized Sep 22 15:29:51 rolyspi2 kernel: [ 4.638771] usbserial: USB Serial support registered for generic Sep 22 15:29:51 rolyspi2 kernel: [ 4.648510] usbcore: registered new interface driver pl2303 Sep 22 15:29:51 rolyspi2 kernel: [ 4.648593] usbserial: USB Serial support registered for pl2303 Sep 22 15:29:51 rolyspi2 kernel: [ 4.648751] pl2303 1-1.4:1.0: pl2303 converter detected Sep 22 15:29:51 rolyspi2 systemd[1]: Starting WPA supplicant... Sep 22 15:29:51 rolyspi2 kernel: [ 4.668979] usb 1-1.4: pl2303 converter now attached to ttyUSB0 Sep 22 15:29:51 rolyspi2 kernel: [ 4.742347] mc: Linux media interface: v0.10 Sep 22 15:29:51 rolyspi2 kernel: [ 4.766370] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 kernel: [ 4.768943] bcm2835_vc_sm_cma_probe: Videocore shared memory driver Sep 22 15:29:51 rolyspi2 kernel: [ 4.768971] [vc_sm_connected_init]: start Sep 22 15:29:51 rolyspi2 kernel: [ 4.776594] [vc_sm_connected_init]: installed successfully Sep 22 15:29:51 rolyspi2 kernel: [ 4.891578] videodev: Linux video capture interface: v2.00 Sep 22 15:29:51 rolyspi2 kernel: [ 4.921284] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 kernel: [ 5.010671] checking generic (3e513000 6e7000) vs hw (0 ffffffffffffffff) Sep 22 15:29:51 rolyspi2 kernel: [ 5.010692] fb0: switching to vc4drmfb from simple Sep 22 15:29:51 rolyspi2 kernel: [ 5.013241] Console: switching to colour dummy device 80x30 Sep 22 15:29:51 rolyspi2 kernel: [ 5.014790] [drm] forcing HDMI-A-1 connector on Sep 22 15:29:51 rolyspi2 kernel: [ 5.015114] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4]) Sep 22 15:29:51 rolyspi2 kernel: [ 5.017840] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0 Sep 22 15:29:51 rolyspi2 kernel: [ 5.092560] cfg80211: Loading compiled-in X.509 certificates for regulatory database Sep 22 15:29:51 rolyspi2 kernel: [ 5.108107] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1 Sep 22 15:29:51 rolyspi2 kernel: [ 5.130725] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 kernel: [ 5.133262] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 kernel: [ 5.138750] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 kernel: [ 5.143436] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 systemd[1]: Started CUPS Scheduler. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Manage Sound Card State (restore and store). Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Save/Restore Sound Card State... Sep 22 15:29:51 rolyspi2 alsactl[430]: alsactl 1.1.8 daemon started Sep 22 15:29:51 rolyspi2 start-ap-managed-wifi.sh[409]: net.ipv4.ip_forward = 1 Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Disk Manager... Sep 22 15:29:51 rolyspi2 systemd[1]: Started openplotter-can-read.service. Sep 22 15:29:51 rolyspi2 dhcpcd[402]: forked to background, child pid 449 Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113). Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: Successfully dropped root privileges. Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: avahi-daemon 0.7 starting up. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting triggerhappy global hotkey daemon... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Helper to synchronize boot up for ifupdown. Sep 22 15:29:51 rolyspi2 systemd[1]: Started rng-tools.service. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Check for v3d driver. Sep 22 15:29:51 rolyspi2 systemd[1]: Started dhcpcd on all interfaces. Sep 22 15:29:51 rolyspi2 thd[452]: Found socket passed from systemd Sep 22 15:29:51 rolyspi2 thd[452]: Device /dev/input/event4 not suitable. Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: Successfully called chroot(). Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: Successfully dropped remaining capabilities. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Save/Restore Sound Card State. Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: No service file found in /etc/avahi/services. Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: Network interface enumeration completed. Sep 22 15:29:51 rolyspi2 avahi-daemon[418]: Server startup complete. Host name is rolyspi2.local. Local service cookie is 1029835672. Sep 22 15:29:51 rolyspi2 dbus-daemon[397]: [system] Successfully activated service 'org.freedesktop.systemd1' Sep 22 15:29:51 rolyspi2 dphys-swapfile[401]: want /var/swap=100MByte, checking existing: keeping it Sep 22 15:29:51 rolyspi2 systemd[1]: Started triggerhappy global hotkey daemon. Sep 22 15:29:51 rolyspi2 rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.1901.0] Sep 22 15:29:51 rolyspi2 rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="421" x-info="https://www.rsyslog.com"] start Sep 22 15:29:51 rolyspi2 systemd[1]: Started System Logging Service. Sep 22 15:29:51 rolyspi2 kernel: [ 5.144812] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Sep 22 15:29:51 rolyspi2 kernel: [ 5.148803] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Sep 22 15:29:51 rolyspi2 kernel: [ 5.160147] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Sep 22 15:29:51 rolyspi2 kernel: [ 5.160206] bcm2835-codec bcm2835-codec: Loaded V4L2 decode Sep 22 15:29:51 rolyspi2 kernel: [ 5.161621] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Sep 22 15:29:51 rolyspi2 kernel: [ 5.162202] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Sep 22 15:29:51 rolyspi2 kernel: [ 5.162783] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Sep 22 15:29:51 rolyspi2 kernel: [ 5.162820] bcm2835-codec bcm2835-codec: Loaded V4L2 encode Sep 22 15:29:51 rolyspi2 kernel: [ 5.162921] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Sep 22 15:29:51 rolyspi2 kernel: [ 5.163479] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Sep 22 15:29:51 rolyspi2 kernel: [ 5.163504] bcm2835-isp bcm2835-isp: Register output node 0 with media controller Sep 22 15:29:51 rolyspi2 kernel: [ 5.167334] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid Sep 22 15:29:51 rolyspi2 kernel: [ 5.169858] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Sep 22 15:29:51 rolyspi2 kernel: [ 5.169881] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Sep 22 15:29:51 rolyspi2 kernel: [ 5.169902] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Sep 22 15:29:51 rolyspi2 kernel: [ 5.170136] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Sep 22 15:29:51 rolyspi2 kernel: [ 5.173688] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Sep 22 15:29:51 rolyspi2 kernel: [ 5.173742] bcm2835-codec bcm2835-codec: Loaded V4L2 isp Sep 22 15:29:51 rolyspi2 kernel: [ 5.209485] bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Sep 22 15:29:51 rolyspi2 kernel: [ 5.209525] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Sep 22 15:29:51 rolyspi2 kernel: [ 5.212015] brcmfmac: F1 signature read @0x18000000=0x15264345 Sep 22 15:29:51 rolyspi2 kernel: [ 5.245590] bcm2835_audio bcm2835_audio: card created with 4 channels Sep 22 15:29:51 rolyspi2 kernel: [ 5.246017] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Sep 22 15:29:51 rolyspi2 kernel: [ 5.252222] usbcore: registered new interface driver brcmfmac Sep 22 15:29:51 rolyspi2 kernel: [ 5.256340] Console: switching to colour frame buffer device 240x67 Sep 22 15:29:51 rolyspi2 kernel: [ 5.267364] bcm2835_audio bcm2835_audio: card created with 4 channels Sep 22 15:29:51 rolyspi2 kernel: [ 5.285255] vc4-drm gpu: [drm] fb0: vc4drmfb frame buffer device Sep 22 15:29:51 rolyspi2 kernel: [ 5.420383] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 Sep 22 15:29:51 rolyspi2 kernel: [ 5.420947] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 Sep 22 15:29:51 rolyspi2 kernel: [ 5.421480] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 Sep 22 15:29:51 rolyspi2 kernel: [ 5.422039] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 Sep 22 15:29:51 rolyspi2 kernel: [ 5.523426] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Sep 22 15:29:51 rolyspi2 kernel: [ 5.529856] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Sep 22 15:29:51 rolyspi2 kernel: [ 5.722494] cdc_acm 1-1.2:1.1: ttyACM0: USB ACM device Sep 22 15:29:51 rolyspi2 kernel: [ 5.723286] usbcore: registered new interface driver cdc_acm Sep 22 15:29:51 rolyspi2 kernel: [ 5.723303] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters Sep 22 15:29:51 rolyspi2 kernel: [ 6.460365] brcmfmac mmc1:0001:1 wlan9: renamed from wlan0 Sep 22 15:29:51 rolyspi2 kernel: [ 6.590300] CAN device driver interface Sep 22 15:29:51 rolyspi2 kernel: [ 7.629446] mcp251x spi0.0: MCP251x didn't enter in conf mode after reset Sep 22 15:29:51 rolyspi2 kernel: [ 7.629640] mcp251x spi0.0: Probe failed, err=110 Sep 22 15:29:51 rolyspi2 kernel: [ 7.629724] mcp251x: probe of spi0.0 failed with error -110 Sep 22 15:29:51 rolyspi2 kernel: [ 7.744522] random: crng init done Sep 22 15:29:51 rolyspi2 kernel: [ 7.744544] random: 7 urandom warning(s) missed due to ratelimiting Sep 22 15:29:51 rolyspi2 kernel: [ 8.002699] 8021q: 802.1Q VLAN Support v1.8 Sep 22 15:29:51 rolyspi2 kernel: [ 8.171146] uart-pl011 fe201000.serial: no DMA platform data Sep 22 15:29:51 rolyspi2 systemd[1]: Reached target Sound Card. Sep 22 15:29:51 rolyspi2 systemd[1]: Starting Raise network interfaces... Sep 22 15:29:51 rolyspi2 systemd[1]: Started Login Service. Sep 22 15:29:51 rolyspi2 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Sep 22 15:29:51 rolyspi2 systemd[1]: Started WPA supplicant. Sep 22 15:29:51 rolyspi2 wpa_supplicant[423]: Successfully initialized wpa_supplicant Sep 22 15:29:51 rolyspi2 raspi-config[383]: Checking if shift key is held down:Device /dev/input/event4 not suitable. Sep 22 15:29:52 rolyspi2 systemd[1]: Started Make remote CUPS printers available locally. Sep 22 15:29:52 rolyspi2 udisksd[441]: udisks daemon version 2.8.1 starting Sep 22 15:29:52 rolyspi2 kernel: [ 8.944236] Adding 102396k swap on /var/swap. Priority:-2 extents:5 across:147452k SSFS Sep 22 15:29:52 rolyspi2 systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file. Sep 22 15:29:52 rolyspi2 dhcpcd-run-hooks[520]: wlan9: starting wpa_supplicant Sep 22 15:29:52 rolyspi2 dhcpcd[449]: wlan9: connected to Access Point `' Sep 22 15:29:52 rolyspi2 dhcpcd[449]: eth0: waiting for carrier Sep 22 15:29:52 rolyspi2 kernel: [ 9.107149] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Sep 22 15:29:52 rolyspi2 kernel: [ 9.107566] bcmgenet fd580000.ethernet eth0: Link is Down Sep 22 15:29:52 rolyspi2 udisksd[441]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory Sep 22 15:29:52 rolyspi2 udisksd[441]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory Sep 22 15:29:52 rolyspi2 dhcpcd[449]: wlan9: waiting for carrier Sep 22 15:29:52 rolyspi2 kernel: [ 9.156233] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled Sep 22 15:29:52 rolyspi2 rpi-eeprom-update[408]: Skipping automatic bootloader upgrade. current 1599135103 >= min 1599135103 Sep 22 15:29:52 rolyspi2 udisksd[441]: Failed to load the 'mdraid' libblockdev plugin Sep 22 15:29:52 rolyspi2 dbus-daemon[397]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=441 comm="/usr/lib/udisks2/udisksd ") Sep 22 15:29:52 rolyspi2 udisksd[441]: Failed to load the 'crypto' libblockdev plugin Sep 22 15:29:52 rolyspi2 systemd[1]: Starting Authorization Manager... Sep 22 15:29:53 rolyspi2 ifup[494]: Cannot find device "can0" Sep 22 15:29:53 rolyspi2 ifup[494]: ifup: failed to bring up can0 Sep 22 15:29:53 rolyspi2 raspi-config[383]: No. Switching to ondemand scaling governor. Sep 22 15:29:53 rolyspi2 systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed). Sep 22 15:29:53 rolyspi2 systemd[1]: networking.service: Main process exited, code=exited, status=1/FAILURE Sep 22 15:29:53 rolyspi2 systemd[1]: networking.service: Failed with result 'exit-code'. Sep 22 15:29:53 rolyspi2 systemd[1]: Failed to start Raise network interfaces. Sep 22 15:29:53 rolyspi2 systemd[1]: Reached target Network. Sep 22 15:29:53 rolyspi2 systemd[1]: Starting Permit User Sessions... Sep 22 15:29:53 rolyspi2 systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Sep 22 15:29:53 rolyspi2 polkitd[542]: started daemon version 0.105 using authority implementation `local' version `0.105' Sep 22 15:29:53 rolyspi2 systemd[1]: Starting OpenBSD Secure Shell server... Sep 22 15:29:53 rolyspi2 dbus-daemon[397]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Sep 22 15:29:53 rolyspi2 systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Sep 22 15:29:53 rolyspi2 systemd[1]: Starting /etc/rc.local Compatibility... Sep 22 15:29:53 rolyspi2 systemd[1]: Started VNC Server in Service Mode daemon. Sep 22 15:29:53 rolyspi2 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Sep 22 15:29:53 rolyspi2 dnsmasq[588]: dnsmasq: syntax check OK. Sep 22 15:29:53 rolyspi2 systemd[1]: Started Permit User Sessions. Sep 22 15:29:53 rolyspi2 systemd[1]: Started /etc/rc.local Compatibility. Sep 22 15:29:53 rolyspi2 systemd[1]: Started Authorization Manager. Sep 22 15:29:53 rolyspi2 systemd[1]: Starting Hold until boot process finishes up... Sep 22 15:29:53 rolyspi2 systemd[1]: Starting Light Display Manager... Sep 22 15:29:53 rolyspi2 hostapd[590]: Configuration file: /etc/hostapd/hostapd.conf Sep 22 15:29:54 rolyspi2 hostapd[590]: wlan9: interface state UNINITIALIZED->HT_SCAN Sep 22 15:29:54 rolyspi2 systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: BOOTLOADER: up to date Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: CURRENT: Thu 3 Sep 12:11:43 UTC 2020 (1599135103) Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: LATEST: Wed 11 Jan 17:40:52 UTC 2023 (1673458852) Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: RELEASE: default (/lib/firmware/raspberrypi/bootloader/default) Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: Use raspi-config to change the release. Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: VL805_FW: Using bootloader EEPROM Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: VL805: up to date Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: CURRENT: 000138a1 Sep 22 15:29:54 rolyspi2 rpi-eeprom-update[408]: LATEST: 000138a1 Sep 22 15:29:54 rolyspi2 systemd[1]: Started Check for Raspberry Pi EEPROM updates. Sep 22 15:29:54 rolyspi2 systemd[1]: Started OpenBSD Secure Shell server. Sep 22 15:29:54 rolyspi2 lightdm[607]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files Sep 22 15:29:54 rolyspi2 dnsmasq[630]: started, version 2.80 cachesize 150 Sep 22 15:29:54 rolyspi2 dnsmasq[630]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Sep 22 15:29:54 rolyspi2 dnsmasq[630]: warning: interface wlan9 does not currently exist Sep 22 15:29:54 rolyspi2 dnsmasq-dhcp[630]: DHCP, IP range 10.10.10.50 -- 10.10.10.200, lease time 12h Sep 22 15:29:54 rolyspi2 dnsmasq[630]: read /etc/hosts - 6 addresses Sep 22 15:29:54 rolyspi2 systemd[1]: Received SIGRTMIN+21 from PID 171 (plymouthd). Sep 22 15:29:54 rolyspi2 systemd[1]: Received SIGRTMIN+21 from PID 171 (plymouthd). Sep 22 15:29:54 rolyspi2 systemd[1]: plymouth-quit-wait.service: Succeeded. Sep 22 15:29:54 rolyspi2 systemd[1]: Started Hold until boot process finishes up. Sep 22 15:29:54 rolyspi2 systemd[1]: Started Light Display Manager. Sep 22 15:29:54 rolyspi2 systemd[1]: Started Getty on tty1. Sep 22 15:29:54 rolyspi2 systemd[1]: Reached target Login Prompts. Sep 22 15:29:54 rolyspi2 systemd[1]: plymouth-start.service: Succeeded. Sep 22 15:29:54 rolyspi2 udisksd[441]: Acquired the name org.freedesktop.UDisks2 on the system message bus Sep 22 15:29:54 rolyspi2 systemd[1]: Started Disk Manager. Sep 22 15:29:54 rolyspi2 dhcpcd[449]: wlan9: carrier acquired Sep 22 15:29:54 rolyspi2 kernel: [ 10.827988] IPv6: ADDRCONF(NETDEV_CHANGE): wlan9: link becomes ready Sep 22 15:29:54 rolyspi2 dhcpcd[449]: wlan9: probing address 10.10.10.1/24 Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: LogDestMem: Start replaying stored messages Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: VendorConfig: Error in Certificate "CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US": X.509 Error: Certificate expired Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: VendorConfig: Error in Certificate "CN=GlobalSign,O=GlobalSign,OU=GlobalSign Root CA - R2": X.509 Error: Certificate expired Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: LogDestMem: Finished replaying stored messages Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: ServerManager: Server started Sep 22 15:29:54 rolyspi2 dnsmasq[630]: no servers found in /run/dnsmasq/resolv.conf, will retry Sep 22 15:29:54 rolyspi2 dnsmasq[631]: Too few arguments. Sep 22 15:29:54 rolyspi2 kernel: [ 11.114396] Under-voltage detected! (0x00050005) Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: SModuleUpdateNotification: Last checked for updates more than 250 days ago Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: ConsoleDisplay: Cannot find a running X server on vt1 Sep 22 15:29:54 rolyspi2 vncserver-x11[610,root]: ConsoleDisplay: Found running X server (pid=639, binary=/usr/lib/xorg/Xorg) Sep 22 15:29:54 rolyspi2 systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Sep 22 15:29:54 rolyspi2 systemd[1]: Reached target Host and Network Name Lookups. Sep 22 15:29:55 rolyspi2 systemd[1]: systemd-rfkill.service: Succeeded. Sep 22 15:29:56 rolyspi2 systemd[1]: openplotter-can-read.service: Succeeded. Sep 22 15:29:56 rolyspi2 avahi-daemon[418]: Joining mDNS multicast group on interface wlan9.IPv6 with address fe80::dea6:32ff:fee0:c844. Sep 22 15:29:56 rolyspi2 avahi-daemon[418]: New relevant interface wlan9.IPv6 for mDNS. Sep 22 15:29:56 rolyspi2 avahi-daemon[418]: Registering new address record for fe80::dea6:32ff:fee0:c844 on wlan9.*. Sep 22 15:29:56 rolyspi2 kernel: [ 13.047128] broken atomic modeset userspace detected, disabling atomic Sep 22 15:29:58 rolyspi2 lightdm[703]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files Sep 22 15:29:58 rolyspi2 systemd[1]: Created slice User Slice of UID 1000. Sep 22 15:29:58 rolyspi2 systemd[1]: Starting User Runtime Directory /run/user/1000... Sep 22 15:29:58 rolyspi2 systemd[1]: Started User Runtime Directory /run/user/1000. Sep 22 15:29:58 rolyspi2 systemd[1]: Starting User Manager for UID 1000... Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on GnuPG network certificate management daemon. Sep 22 15:29:59 rolyspi2 systemd[708]: Starting D-Bus User Message Bus Socket. Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on GnuPG cryptographic agent and passphrase cache. Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Sep 22 15:29:59 rolyspi2 systemd[708]: Reached target Timers. Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on Sound System. Sep 22 15:29:59 rolyspi2 systemd[708]: Reached target Paths. Sep 22 15:29:59 rolyspi2 systemd[708]: Listening on D-Bus User Message Bus Socket. Sep 22 15:29:59 rolyspi2 systemd[708]: Reached target Sockets. Sep 22 15:29:59 rolyspi2 systemd[708]: Reached target Basic System. Sep 22 15:29:59 rolyspi2 systemd[708]: Reached target Default. Sep 22 15:29:59 rolyspi2 systemd[708]: Startup finished in 650ms. Sep 22 15:29:59 rolyspi2 systemd[1]: Started User Manager for UID 1000. Sep 22 15:29:59 rolyspi2 systemd[1]: Started Session 1 of user pi. Sep 22 15:29:59 rolyspi2 dhcpcd[449]: wlan9: using static address 10.10.10.1/24 Sep 22 15:29:59 rolyspi2 avahi-daemon[418]: Joining mDNS multicast group on interface wlan9.IPv4 with address 10.10.10.1. Sep 22 15:29:59 rolyspi2 avahi-daemon[418]: New relevant interface wlan9.IPv4 for mDNS. Sep 22 15:29:59 rolyspi2 avahi-daemon[418]: Registering new address record for 10.10.10.1 on wlan9.IPv4. Sep 22 15:29:59 rolyspi2 dhcpcd[449]: wlan9: adding route to 10.10.10.0/24 Sep 22 15:29:59 rolyspi2 dhcpcd[449]: wlan9: adding default route via 10.10.10.1 Sep 22 15:29:59 rolyspi2 systemd[708]: Started D-Bus User Message Bus. Sep 22 15:29:59 rolyspi2 dnsmasq[630]: reading /run/dnsmasq/resolv.conf Sep 22 15:29:59 rolyspi2 dnsmasq[630]: using nameserver 8.8.8.8#53 Sep 22 15:29:59 rolyspi2 systemd[1]: Started Session 3 of user pi. Sep 22 15:30:00 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=729 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ") Sep 22 15:30:00 rolyspi2 systemd[708]: Starting Virtual filesystem service... Sep 22 15:30:01 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.Daemon' Sep 22 15:30:01 rolyspi2 systemd[708]: Started Virtual filesystem service. Sep 22 15:30:01 rolyspi2 kernel: [ 17.418138] Bluetooth: Core ver 2.22 Sep 22 15:30:01 rolyspi2 kernel: [ 17.418271] NET: Registered protocol family 31 Sep 22 15:30:01 rolyspi2 kernel: [ 17.418290] Bluetooth: HCI device and connection manager initialized Sep 22 15:30:01 rolyspi2 kernel: [ 17.418324] Bluetooth: HCI socket layer initialized Sep 22 15:30:01 rolyspi2 kernel: [ 17.418351] Bluetooth: L2CAP socket layer initialized Sep 22 15:30:01 rolyspi2 kernel: [ 17.418390] Bluetooth: SCO socket layer initialized Sep 22 15:30:01 rolyspi2 kernel: [ 17.440626] Bluetooth: HCI UART driver ver 2.3 Sep 22 15:30:01 rolyspi2 kernel: [ 17.440661] Bluetooth: HCI UART protocol H4 registered Sep 22 15:30:01 rolyspi2 kernel: [ 17.440819] Bluetooth: HCI UART protocol Three-wire (H5) registered Sep 22 15:30:01 rolyspi2 kernel: [ 17.445641] Bluetooth: HCI UART protocol Broadcom registered Sep 22 15:30:01 rolyspi2 btuart[429]: bcm43xx_init Sep 22 15:30:01 rolyspi2 btuart[429]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Sep 22 15:30:01 rolyspi2 btuart[429]: Set Controller UART speed to 3000000 bit/s Sep 22 15:30:01 rolyspi2 btuart[429]: Device setup complete Sep 22 15:30:01 rolyspi2 systemd[1]: Starting Load/Save RF Kill Switch Status... Sep 22 15:30:01 rolyspi2 systemd[1]: Started Configure Bluetooth Modems connected by UART. Sep 22 15:30:01 rolyspi2 systemd[1]: Reached target Multi-User System. Sep 22 15:30:01 rolyspi2 systemd[1]: Reached target Graphical Interface. Sep 22 15:30:01 rolyspi2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 22 15:30:01 rolyspi2 kernel: [ 17.586409] fuse: init (API version 7.32) Sep 22 15:30:01 rolyspi2 systemd[1]: Started Load/Save RF Kill Switch Status. Sep 22 15:30:01 rolyspi2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 22 15:30:01 rolyspi2 systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 22 15:30:01 rolyspi2 systemd[1]: Mounting FUSE Control File System... Sep 22 15:30:01 rolyspi2 systemd[1]: Created slice system-bthelper.slice. Sep 22 15:30:01 rolyspi2 systemd[1]: Starting Raspberry Pi bluetooth helper... Sep 22 15:30:01 rolyspi2 systemd[1]: Mounted FUSE Control File System. Sep 22 15:30:01 rolyspi2 bthelper[878]: Raspberry Pi BDADDR already set Sep 22 15:30:01 rolyspi2 systemd[1]: Started Raspberry Pi bluetooth helper. Sep 22 15:30:01 rolyspi2 systemd[1]: Starting Bluetooth service... Sep 22 15:30:01 rolyspi2 bluetoothd[896]: Bluetooth daemon 5.50 Sep 22 15:30:01 rolyspi2 systemd[1]: Started Bluetooth service. Sep 22 15:30:01 rolyspi2 systemd[1]: Reached target Bluetooth. Sep 22 15:30:01 rolyspi2 systemd[1]: Startup finished in 2.115s (kernel) + 16.030s (userspace) = 18.146s. Sep 22 15:30:01 rolyspi2 bluetoothd[896]: Starting SDP server Sep 22 15:30:01 rolyspi2 kernel: [ 18.197451] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Sep 22 15:30:01 rolyspi2 kernel: [ 18.197475] Bluetooth: BNEP filters: protocol multicast Sep 22 15:30:01 rolyspi2 kernel: [ 18.197510] Bluetooth: BNEP socket layer initialized Sep 22 15:30:01 rolyspi2 bluetoothd[896]: Bluetooth management interface 1.18 initialized Sep 22 15:30:01 rolyspi2 dbus-daemon[397]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.21' (uid=0 pid=896 comm="/usr/lib/bluetooth/bluetoothd ") Sep 22 15:30:01 rolyspi2 bluetoothd[896]: Sap driver initialization failed. Sep 22 15:30:01 rolyspi2 bluetoothd[896]: sap-server: Operation not permitted (1) Sep 22 15:30:01 rolyspi2 vncserver-x11[610,root]: SModuleUpdateNotification: Last checked for updates more than 250 days ago Sep 22 15:30:01 rolyspi2 systemd[1]: Starting Hostname Service... Sep 22 15:30:02 rolyspi2 systemd[708]: Starting Sound Service... Sep 22 15:30:02 rolyspi2 bluetoothd[896]: Failed to set privacy: Rejected (0x0b) Sep 22 15:30:02 rolyspi2 dbus-daemon[397]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.22' (uid=1000 pid=924 comm="/usr/bin/pulseaudio --daemonize=no ") Sep 22 15:30:02 rolyspi2 dbus-daemon[397]: [system] Successfully activated service 'org.freedesktop.hostname1' Sep 22 15:30:02 rolyspi2 systemd[1]: Starting RealtimeKit Scheduling Policy Service... Sep 22 15:30:02 rolyspi2 systemd[1]: Started Hostname Service. Sep 22 15:30:02 rolyspi2 dbus-daemon[397]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Sep 22 15:30:02 rolyspi2 systemd[1]: Started RealtimeKit Scheduling Policy Service. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Successfully called chroot. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Successfully dropped privileges. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Successfully limited resources. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Running. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Canary thread running. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Watchdog thread running. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Successfully made thread 924 of process 924 (n/a) owned by '1000' high priority at nice level -11. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Supervising 1 threads of 1 processes of 1 users. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Supervising 1 threads of 1 processes of 1 users. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Successfully made thread 943 of process 924 (n/a) owned by '1000' RT at priority 5. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Supervising 2 threads of 1 processes of 1 users. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Supervising 2 threads of 1 processes of 1 users. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Successfully made thread 944 of process 924 (n/a) owned by '1000' RT at priority 5. Sep 22 15:30:02 rolyspi2 rtkit-daemon[931]: Supervising 3 threads of 1 processes of 1 users. Sep 22 15:30:02 rolyspi2 systemd[708]: Started Sound Service. Sep 22 15:30:02 rolyspi2 bluetoothd[896]: Endpoint registered: sender=:1.27 path=/MediaEndpoint/A2DPSource Sep 22 15:30:02 rolyspi2 bluetoothd[896]: Endpoint registered: sender=:1.27 path=/MediaEndpoint/A2DPSink Sep 22 15:30:02 rolyspi2 pulseaudio[924]: E: [pulseaudio] backend-ofono.c: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Sep 22 15:30:02 rolyspi2 kernel: [ 19.286097] Bluetooth: RFCOMM TTY layer initialized Sep 22 15:30:02 rolyspi2 kernel: [ 19.286144] Bluetooth: RFCOMM socket layer initialized Sep 22 15:30:02 rolyspi2 kernel: [ 19.286201] Bluetooth: RFCOMM ver 1.11 Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=868 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:30:03 rolyspi2 systemd[708]: Starting Virtual filesystem service - disk device monitor... Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor' Sep 22 15:30:03 rolyspi2 systemd[708]: Started Virtual filesystem service - disk device monitor. Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=868 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:30:03 rolyspi2 systemd[708]: Starting Virtual filesystem service - Apple File Conduit monitor... Sep 22 15:30:03 rolyspi2 gvfs-afc-volume-monitor[952]: Volume monitor alive Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor' Sep 22 15:30:03 rolyspi2 systemd[708]: Started Virtual filesystem service - Apple File Conduit monitor. Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=868 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:30:03 rolyspi2 systemd[708]: Starting Virtual filesystem service - GNOME Online Accounts monitor... Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor' Sep 22 15:30:03 rolyspi2 systemd[708]: Started Virtual filesystem service - GNOME Online Accounts monitor. Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=868 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:30:03 rolyspi2 systemd[708]: Starting Virtual filesystem service - digital camera monitor... Sep 22 15:30:03 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor' Sep 22 15:30:03 rolyspi2 systemd[708]: Started Virtual filesystem service - digital camera monitor. Sep 22 15:30:04 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=868 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:30:04 rolyspi2 systemd[708]: Starting Virtual filesystem service - Media Transfer Protocol monitor... Sep 22 15:30:04 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor' Sep 22 15:30:04 rolyspi2 systemd[708]: Started Virtual filesystem service - Media Transfer Protocol monitor. Sep 22 15:30:05 rolyspi2 gvfsd[837]: Error 1: Get Storage information failed. Sep 22 15:30:06 rolyspi2 pulseaudio[924]: E: [alsa-sink-bcm2835 HDMI 1] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write. Sep 22 15:30:06 rolyspi2 pulseaudio[924]: E: [alsa-sink-bcm2835 HDMI 1] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_bcm2835'. Please report this issue to the ALSA developers. Sep 22 15:30:06 rolyspi2 pulseaudio[924]: E: [alsa-sink-bcm2835 HDMI 1] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail. Sep 22 15:30:06 rolyspi2 systemd[1]: systemd-rfkill.service: Succeeded. Sep 22 15:30:06 rolyspi2 bthelper[878]: Changing power off succeeded Sep 22 15:30:06 rolyspi2 bthelper[878]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Powered: no Sep 22 15:30:06 rolyspi2 bthelper[878]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Discovering: no Sep 22 15:30:06 rolyspi2 bthelper[878]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Class: 0x00000000 Sep 22 15:30:06 rolyspi2 bthelper[878]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Class: 0x000c0000 Sep 22 15:30:06 rolyspi2 bthelper[878]: Changing power on succeeded Sep 22 15:30:06 rolyspi2 bthelper[878]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:E0:C8:45 Powered: yes Sep 22 15:30:11 rolyspi2 kernel: [ 28.151762] can: controller area network core Sep 22 15:30:11 rolyspi2 kernel: [ 28.151884] NET: Registered protocol family 29 Sep 22 15:30:11 rolyspi2 kernel: [ 28.162421] can: raw protocol Sep 22 15:30:11 rolyspi2 signalk-server[412]: unable to open canbus can0: Error: Error while creating channel Sep 22 15:30:11 rolyspi2 signalk-server[412]: Error: Error while creating channel Sep 22 15:30:11 rolyspi2 signalk-server[412]: at Object.exports.createRawChannelWithOptions (/usr/lib/node_modules/signalk-server/node_modules/socketcan/socketcan.js:56:12) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at new CanbusStream (/usr/lib/node_modules/signalk-server/node_modules/@canboat/canboatjs/lib/canbus.js:123:32) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at CanbusStream (/usr/lib/node_modules/signalk-server/node_modules/@canboat/canboatjs/lib/canbus.js:47:12) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at Object.nmea2000input [as NMEA2000] (/usr/lib/node_modules/signalk-server/node_modules/@signalk/streams/simple.js:233:30) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at new Simple (/usr/lib/node_modules/signalk-server/node_modules/@signalk/streams/simple.js:79:34) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at createPipeElement (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:75:16) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at result.pipeElements.providerConfig.pipeElements.reduce (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:48:30) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at Array.reduce () Sep 22 15:30:11 rolyspi2 signalk-server[412]: at createPipedProvider (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:46:55) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at app.config.settings.pipedProviders.reduce (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:82:37) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at Array.reduce () Sep 22 15:30:11 rolyspi2 signalk-server[412]: at Object.startProviders [as start] (/usr/lib/node_modules/signalk-server/lib/pipedproviders.js:79:62) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at createServer (/usr/lib/node_modules/signalk-server/lib/index.js:280:66) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at createServer (/usr/lib/node_modules/signalk-server/lib/index.js:398:5) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at Promise (/usr/lib/node_modules/signalk-server/lib/index.js:267:13) Sep 22 15:30:11 rolyspi2 signalk-server[412]: at new Promise () Sep 22 15:30:11 rolyspi2 signalk-server[412]: signalk-server running at 0.0.0.0:[object Object] Sep 22 15:30:11 rolyspi2 signalk-server[412]: Error: No such file or directory, cannot open /dev/serial/by-id/usb-VesperMarine_Vesper_Marine_AIS_VESPERMARINE-if00-port0 Sep 22 15:30:29 rolyspi2 kernel: [ 30.332775] v3d fec00000.v3d: MMU error from client L2T (0) at 0x1ea1000, pte invalid Sep 22 15:30:31 rolyspi2 signalk-server[412]: unable to check for new server version: FetchError: request to http://registry.npmjs.org/-/package/signalk-server/dist-tags failed, reason: getaddrinfo EAI_AGAIN registry.npmjs.org registry.npmjs.org:80 Sep 22 15:30:36 rolyspi2 systemd[1]: systemd-fsckd.service: Succeeded. Sep 22 15:30:40 rolyspi2 kernel: [ 40.788324] usb 1-1.2: USB disconnect, device number 4 Sep 22 15:30:40 rolyspi2 gvfsd[837]: PTP: reading event an error 0x05 occurred Sep 22 15:30:40 rolyspi2 kernel: [ 41.204175] usb 1-1.2: new high-speed USB device number 7 using xhci_hcd Sep 22 15:30:40 rolyspi2 kernel: [ 41.335280] usb 1-1.2: New USB device found, idVendor=04e8, idProduct=6860, bcdDevice= 4.19 Sep 22 15:30:40 rolyspi2 kernel: [ 41.335290] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 22 15:30:40 rolyspi2 kernel: [ 41.335298] usb 1-1.2: Product: SAMSUNG_Android Sep 22 15:30:40 rolyspi2 kernel: [ 41.335304] usb 1-1.2: Manufacturer: SAMSUNG Sep 22 15:30:40 rolyspi2 kernel: [ 41.335311] usb 1-1.2: SerialNumber: R58W30ZMK6N Sep 22 15:30:40 rolyspi2 kernel: [ 41.340251] cdc_acm 1-1.2:1.1: ttyACM0: USB ACM device Sep 22 15:30:41 rolyspi2 gvfsd[837]: Device 0 (VID=04e8 and PID=6860) is a Samsung Galaxy models (MTP). Sep 22 15:30:41 rolyspi2 kernel: [ 42.314265] Voltage normalised (0x00000000) Sep 22 15:30:43 rolyspi2 kernel: [ 43.860680] usb 1-1.2: USB disconnect, device number 7 Sep 22 15:30:43 rolyspi2 gvfsd[837]: PTP: reading event an error 0x05 occurred Sep 22 15:30:43 rolyspi2 kernel: [ 44.314179] usb 1-1.2: new high-speed USB device number 8 using xhci_hcd Sep 22 15:30:43 rolyspi2 kernel: [ 44.445203] usb 1-1.2: New USB device found, idVendor=04e8, idProduct=6863, bcdDevice= 4.19 Sep 22 15:30:43 rolyspi2 kernel: [ 44.445214] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 22 15:30:43 rolyspi2 kernel: [ 44.445222] usb 1-1.2: Product: SAMSUNG_Android Sep 22 15:30:43 rolyspi2 kernel: [ 44.445228] usb 1-1.2: Manufacturer: SAMSUNG Sep 22 15:30:43 rolyspi2 kernel: [ 44.445236] usb 1-1.2: SerialNumber: R58W30ZMK6N Sep 22 15:30:43 rolyspi2 mtp-probe: checking bus 1, device 8: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2" Sep 22 15:30:43 rolyspi2 mtp-probe: bus: 1, device: 8 was not an MTP device Sep 22 15:30:43 rolyspi2 kernel: [ 44.476332] usbcore: registered new interface driver cdc_ether Sep 22 15:30:43 rolyspi2 kernel: [ 44.480293] rndis_host 1-1.2:1.0: rndis media connect Sep 22 15:30:44 rolyspi2 kernel: [ 44.535333] rndis_host 1-1.2:1.0 usb0: register 'rndis_host' at usb-0000:01:00.0-1.2, RNDIS device, e6:ef:78:28:38:2a Sep 22 15:30:44 rolyspi2 kernel: [ 44.537027] usbcore: registered new interface driver rndis_host Sep 22 15:30:44 rolyspi2 mtp-probe: checking bus 1, device 8: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2" Sep 22 15:30:44 rolyspi2 mtp-probe: bus: 1, device: 8 was not an MTP device Sep 22 15:30:44 rolyspi2 systemd-udevd[1185]: Using default interface naming scheme 'v240'. Sep 22 15:30:44 rolyspi2 avahi-daemon[418]: Joining mDNS multicast group on interface usb0.IPv4 with address 192.168.42.10. Sep 22 15:30:44 rolyspi2 avahi-daemon[418]: New relevant interface usb0.IPv4 for mDNS. Sep 22 15:30:44 rolyspi2 avahi-daemon[418]: Registering new address record for 192.168.42.10 on usb0.IPv4. Sep 22 15:30:44 rolyspi2 dhcpcd[449]: usb0: waiting for carrier Sep 22 15:30:44 rolyspi2 dhcpcd[449]: usb0: carrier acquired Sep 22 15:30:44 rolyspi2 gvfsd[837]: Device 0 (VID=04e8 and PID=6860) is a Samsung Galaxy models (MTP). Sep 22 15:30:44 rolyspi2 dhcpcd[449]: usb0: soliciting a DHCP lease Sep 22 15:30:45 rolyspi2 avahi-daemon[418]: Joining mDNS multicast group on interface usb0.IPv6 with address fe80::e4ef:78ff:fe28:382a. Sep 22 15:30:45 rolyspi2 avahi-daemon[418]: New relevant interface usb0.IPv6 for mDNS. Sep 22 15:30:45 rolyspi2 avahi-daemon[418]: Registering new address record for fe80::e4ef:78ff:fe28:382a on usb0.*. Sep 22 15:30:45 rolyspi2 kernel: [ 46.474332] Under-voltage detected! (0x00050005) Sep 22 15:30:48 rolyspi2 systemd[1]: systemd-hostnamed.service: Succeeded. Sep 22 15:30:48 rolyspi2 systemd[1]: openplotter-network.service: Succeeded. Sep 22 15:30:49 rolyspi2 dhcpcd[449]: usb0: probing for an IPv4LL address Sep 22 15:30:55 rolyspi2 dhcpcd[449]: usb0: using IPv4LL address 169.254.187.137 Sep 22 15:30:55 rolyspi2 dhcpcd[449]: usb0: adding route to 169.254.0.0/16 Sep 22 15:30:55 rolyspi2 avahi-daemon[418]: Registering new address record for 169.254.187.137 on usb0.IPv4. Sep 22 15:33:38 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Activating via systemd: service name='org.gtk.vfs.Metadata' unit='gvfs-metadata.service' requested by ':1.7' (uid=1000 pid=868 comm="pcmanfm --desktop --profile LXDE-pi ") Sep 22 15:33:38 rolyspi2 systemd[708]: Starting Virtual filesystem metadata service... Sep 22 15:33:38 rolyspi2 dbus-daemon[753]: [session uid=1000 pid=753] Successfully activated service 'org.gtk.vfs.Metadata' Sep 22 15:33:38 rolyspi2 systemd[708]: Started Virtual filesystem metadata service. Sep 22 15:34:11 rolyspi2 kernel: [ 252.394216] Voltage normalised (0x00000000) Sep 22 15:34:14 rolyspi2 kernel: [ 254.476928] Under-voltage detected! (0x00050005) Sep 22 15:34:50 rolyspi2 kernel: [ 291.914201] Voltage normalised (0x00000000) Sep 22 15:35:43 rolyspi2 kernel: [ 343.914295] rpi_firmware_get_throttled: 1 callbacks suppressed Sep 22 15:35:43 rolyspi2 kernel: [ 343.914305] Under-voltage detected! (0x00050005) Sep 22 15:35:47 rolyspi2 kernel: [ 348.074212] rpi_firmware_get_throttled: 1 callbacks suppressed Sep 22 15:35:47 rolyspi2 kernel: [ 348.074216] Voltage normalised (0x00000000) Sep 22 15:35:49 rolyspi2 kernel: [ 350.154583] Under-voltage detected! (0x00050005) Sep 22 15:36:01 rolyspi2 kernel: [ 362.634230] Voltage normalised (0x00000000) Sep 22 15:36:03 rolyspi2 kernel: [ 364.714572] Under-voltage detected! (0x00050005) Sep 22 15:36:12 rolyspi2 kernel: [ 373.034215] Voltage normalised (0x00000000) Sep 22 15:41:16 rolyspi2 kernel: [ 676.714333] rpi_firmware_get_throttled: 4 callbacks suppressed Sep 22 15:41:16 rolyspi2 kernel: [ 676.714342] Under-voltage detected! (0x00050005) Sep 22 15:41:20 rolyspi2 kernel: [ 680.874214] rpi_firmware_get_throttled: 4 callbacks suppressed Sep 22 15:41:20 rolyspi2 kernel: [ 680.874218] Voltage normalised (0x00000000) Sep 22 15:41:41 rolyspi2 kernel: [ 701.684326] Under-voltage detected! (0x00050005) Sep 22 15:41:45 rolyspi2 kernel: [ 705.834211] Voltage normalised (0x00000000) Sep 22 15:42:10 rolyspi2 kernel: [ 730.794546] Under-voltage detected! (0x00050005) Sep 22 15:42:29 rolyspi2 kernel: [ 749.514220] Voltage normalised (0x00000000)