-- Logs begin at Thu 2019-02-14 05:12:00 EST, end at Sun 2024-09-29 11:19:58 EDT. -- Sep 29 11:19:18 garage kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Sep 29 11:19:18 garage kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Sep 29 11:19:18 garage kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Sep 29 11:19:18 garage kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Sep 29 11:19:18 garage kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 29 11:19:18 garage kernel: usb usb1: Product: xHCI Host Controller Sep 29 11:19:18 garage kernel: usb usb1: Manufacturer: Linux 6.1.69-v7l+ xhci-hcd Sep 29 11:19:18 garage kernel: usb usb1: SerialNumber: 0000:01:00.0 Sep 29 11:19:18 garage kernel: hub 1-0:1.0: USB hub found Sep 29 11:19:18 garage kernel: hub 1-0:1.0: 1 port detected Sep 29 11:19:18 garage kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.01 Sep 29 11:19:18 garage kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 29 11:19:18 garage kernel: usb usb2: Product: xHCI Host Controller Sep 29 11:19:18 garage kernel: usb usb2: Manufacturer: Linux 6.1.69-v7l+ xhci-hcd Sep 29 11:19:18 garage kernel: usb usb2: SerialNumber: 0000:01:00.0 Sep 29 11:19:18 garage kernel: hub 2-0:1.0: USB hub found Sep 29 11:19:18 garage kernel: hub 2-0:1.0: 4 ports detected Sep 29 11:19:18 garage kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Sep 29 11:19:18 garage kernel: dwc_otg: FIQ enabled Sep 29 11:19:18 garage kernel: dwc_otg: NAK holdoff enabled Sep 29 11:19:18 garage kernel: dwc_otg: FIQ split-transaction FSM enabled Sep 29 11:19:18 garage kernel: Module dwc_common_port init Sep 29 11:19:18 garage kernel: usbcore: registered new interface driver uas Sep 29 11:19:18 garage kernel: usbcore: registered new interface driver usb-storage Sep 29 11:19:18 garage kernel: mousedev: PS/2 mouse device common for all mice Sep 29 11:19:18 garage kernel: sdhci: Secure Digital Host Controller Interface driver Sep 29 11:19:18 garage kernel: sdhci: Copyright(c) Pierre Ossman Sep 29 11:19:18 garage kernel: sdhci-pltfm: SDHCI platform and OF driver helper Sep 29 11:19:18 garage kernel: ledtrig-cpu: registered to indicate activity on CPUs Sep 29 11:19:18 garage kernel: hid: raw HID events driver (C) Jiri Kosina Sep 29 11:19:18 garage kernel: usbcore: registered new interface driver usbhid Sep 29 11:19:18 garage kernel: usbhid: USB HID core driver Sep 29 11:19:18 garage kernel: Initializing XFRM netlink socket Sep 29 11:19:18 garage kernel: NET: Registered PF_PACKET protocol family Sep 29 11:19:18 garage kernel: Key type dns_resolver registered Sep 29 11:19:18 garage kernel: Registering SWP/SWPB emulation handler Sep 29 11:19:18 garage kernel: registered taskstats version 1 Sep 29 11:19:18 garage kernel: Loading compiled-in X.509 certificates Sep 29 11:19:18 garage kernel: Key type .fscrypt registered Sep 29 11:19:18 garage kernel: Key type fscrypt-provisioning registered Sep 29 11:19:18 garage kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Sep 29 11:19:18 garage kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Sep 29 11:19:18 garage kernel: fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 51, base_baud = 0) is a PL011 rev2 Sep 29 11:19:18 garage kernel: serial serial0: tty port ttyAMA1 registered Sep 29 11:19:18 garage kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Sep 29 11:19:18 garage kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Sep 29 11:19:18 garage kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Sep 29 11:19:18 garage kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Sep 29 11:19:18 garage kernel: of_cfs_init Sep 29 11:19:18 garage kernel: of_cfs_init: OK Sep 29 11:19:18 garage kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Sep 29 11:19:18 garage kernel: Freeing unused kernel image (initmem) memory: 2048K Sep 29 11:19:18 garage kernel: Run /init as init process Sep 29 11:19:18 garage kernel: with arguments: Sep 29 11:19:18 garage kernel: /init Sep 29 11:19:18 garage kernel: splash Sep 29 11:19:18 garage kernel: nodebug Sep 29 11:19:18 garage kernel: with environment: Sep 29 11:19:18 garage kernel: HOME=/ Sep 29 11:19:18 garage kernel: TERM=linux Sep 29 11:19:18 garage kernel: imgpart=UUID=0c3a77ec-ae84-4f1b-8028-c61cc251ffe5 Sep 29 11:19:18 garage kernel: imgfile=/volumio_current.sqsh Sep 29 11:19:18 garage kernel: bootpart=UUID=41CA-9A8B Sep 29 11:19:18 garage kernel: datapart=UUID=0324d53a-d066-482b-b659-eb98af2b49e7 Sep 29 11:19:18 garage kernel: uuidconfig=cmdline.txt Sep 29 11:19:18 garage kernel: pcie_aspm=off Sep 29 11:19:18 garage kernel: bootdelay=7 Sep 29 11:19:18 garage kernel: use_kmsg=no Sep 29 11:19:18 garage kernel: mmc1: new high speed SDIO card at address 0001 Sep 29 11:19:18 garage kernel: mmc0: new ultra high speed DDR50 SDXC card at address aaaa Sep 29 11:19:18 garage kernel: mmcblk0: mmc0:aaaa SL64G 59.5 GiB Sep 29 11:19:18 garage kernel: mmcblk0: p1 p2 p3 Sep 29 11:19:18 garage kernel: mmcblk0: mmc0:aaaa SL64G 59.5 GiB (quirks 0x00004000) Sep 29 11:19:18 garage kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Sep 29 11:19:18 garage kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Sep 29 11:19:18 garage kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Sep 29 11:19:18 garage kernel: usb 1-1: Product: USB2.0 Hub Sep 29 11:19:18 garage kernel: hub 1-1:1.0: USB hub found Sep 29 11:19:18 garage kernel: hub 1-1:1.0: 4 ports detected Sep 29 11:19:18 garage kernel: fuse: init (API version 7.37) Sep 29 11:19:18 garage kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Sep 29 11:19:18 garage kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Sep 29 11:19:18 garage kernel: EXT4-fs (mmcblk0p2): recovery complete Sep 29 11:19:18 garage kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Sep 29 11:19:18 garage kernel: loop0: detected capacity change from 0 to 983416 Sep 29 11:19:18 garage kernel: EXT4-fs (mmcblk0p3): recovery complete Sep 29 11:19:18 garage kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Sep 29 11:19:18 garage systemd[1]: System time before build time, advancing clock. Sep 29 11:19:18 garage kernel: NET: Registered PF_INET6 protocol family Sep 29 11:19:18 garage kernel: Segment Routing with IPv6 Sep 29 11:19:18 garage kernel: In-situ OAM (IOAM) with IPv6 Sep 29 11:19:18 garage systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Sep 29 11:19:18 garage systemd[1]: Detected architecture arm. Sep 29 11:19:18 garage systemd[1]: Set hostname to . Sep 29 11:19:18 garage systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Sep 29 11:19:18 garage systemd[1]: Listening on Journal Socket. Sep 29 11:19:18 garage systemd[1]: Listening on udev Kernel Socket. Sep 29 11:19:18 garage systemd[1]: Listening on udev Control Socket. Sep 29 11:19:18 garage systemd[1]: Created slice User and Session Slice. Sep 29 11:19:18 garage systemd[1]: Mounting POSIX Message Queue File System... Sep 29 11:19:18 garage systemd[1]: Reached target Slices. Sep 29 11:19:18 garage kernel: i2c_dev: i2c /dev entries driver Sep 29 11:19:18 garage systemd-journald[331]: Journal started Sep 29 11:19:18 garage systemd-journald[331]: Runtime journal (/run/log/journal/d5012141e8efab18115b4334669e938a) is 7.5M, max 30.0M, 22.5M free. Sep 29 11:19:18 garage systemd-modules-load[321]: Inserted module 'i2c_dev' Sep 29 11:19:18 garage fake-hwclock[332]: Sun Sep 29 15:19:18 UTC 2024 Sep 29 11:19:18 garage systemd[1]: Started Create System Users. Sep 29 11:19:18 garage systemd[1]: Starting Create Static Device Nodes in /dev... Sep 29 11:19:18 garage systemd[1]: Started udev Coldplug all Devices. Sep 29 11:19:18 garage systemd[1]: Starting Helper to synchronize boot up for ifupdown... Sep 29 11:19:18 garage systemd[1]: Started Create Static Device Nodes in /dev. Sep 29 11:19:18 garage systemd[1]: Reached target Local File Systems (Pre). Sep 29 11:19:18 garage systemd[1]: Mounting /var/spool/cups... Sep 29 11:19:18 garage systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Sep 29 11:19:18 garage systemd[1]: Mounting /var/log... Sep 29 11:19:18 garage systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Sep 29 11:19:18 garage systemd[1]: Mounting /tmp... Sep 29 11:19:18 garage systemd[1]: Starting udev Kernel Device Manager... Sep 29 11:19:18 garage systemd[1]: Mounted /var/spool/cups. Sep 29 11:19:18 garage systemd[1]: Mounted /var/log. Sep 29 11:19:18 garage systemd[1]: Mounted /tmp. Sep 29 11:19:18 garage systemd[1]: Starting Flush Journal to Persistent Storage... Sep 29 11:19:18 garage systemd[1]: Mounting /var/spool/cups/tmp... Sep 29 11:19:18 garage systemd[1]: Mounted /var/spool/cups/tmp. Sep 29 11:19:18 garage systemd-udevd[360]: Network interface NamePolicy= disabled on kernel command line, ignoring. Sep 29 11:19:18 garage systemd-journald[331]: Runtime journal (/run/log/journal/d5012141e8efab18115b4334669e938a) is 7.5M, max 30.0M, 22.5M free. Sep 29 11:19:18 garage systemd[1]: Started Flush Journal to Persistent Storage. Sep 29 11:19:18 garage systemd[1]: Started udev Kernel Device Manager. Sep 29 11:19:18 garage systemd[1]: Starting Show Plymouth Boot Screen... Sep 29 11:19:18 garage systemd[1]: plymouth-start.service: Succeeded. Sep 29 11:19:18 garage systemd[1]: Started Show Plymouth Boot Screen. Sep 29 11:19:18 garage systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Sep 29 11:19:18 garage systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 29 11:19:18 garage systemd[1]: Reached target Paths. Sep 29 11:19:18 garage systemd[1]: Reached target Local Encrypted Volumes. Sep 29 11:19:18 garage systemd-udevd[371]: Using default interface naming scheme 'v240'. Sep 29 11:19:18 garage systemd-udevd[371]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 29 11:19:18 garage kernel: mc: Linux media interface: v0.10 Sep 29 11:19:18 garage kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:18 garage kernel: videodev: Linux video capture interface: v2.00 Sep 29 11:19:19 garage kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Sep 29 11:19:19 garage kernel: [vc_sm_connected_init]: start Sep 29 11:19:19 garage kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Sep 29 11:19:19 garage kernel: [vc_sm_connected_init]: installed successfully Sep 29 11:19:19 garage kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Sep 29 11:19:19 garage kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Sep 29 11:19:19 garage kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: Bluetooth: Core ver 2.22 Sep 29 11:19:19 garage kernel: NET: Registered PF_BLUETOOTH protocol family Sep 29 11:19:19 garage kernel: Bluetooth: HCI device and connection manager initialized Sep 29 11:19:19 garage kernel: Bluetooth: HCI socket layer initialized Sep 29 11:19:19 garage kernel: Bluetooth: L2CAP socket layer initialized Sep 29 11:19:19 garage kernel: Bluetooth: SCO socket layer initialized Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Sep 29 11:19:19 garage kernel: rpivid feb10000.codec: Device registered as /dev/video19 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Sep 29 11:19:19 garage kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Sep 29 11:19:19 garage kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Sep 29 11:19:19 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Sep 29 11:19:19 garage kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Sep 29 11:19:19 garage kernel: Bluetooth: HCI UART driver ver 2.3 Sep 29 11:19:19 garage kernel: Bluetooth: HCI UART protocol H4 registered Sep 29 11:19:19 garage kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Sep 29 11:19:19 garage kernel: Bluetooth: HCI UART protocol Broadcom registered Sep 29 11:19:19 garage kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Sep 29 11:19:19 garage kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Sep 29 11:19:19 garage kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Sep 29 11:19:19 garage kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Sep 29 11:19:19 garage kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Sep 29 11:19:19 garage kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Sep 29 11:19:19 garage systemd-udevd[369]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 29 11:19:19 garage kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Sep 29 11:19:20 garage kernel: uart-pl011 fe201000.serial: no DMA platform data Sep 29 11:19:20 garage systemd[1]: Found device /dev/disk/by-uuid/41CA-9A8B. Sep 29 11:19:20 garage kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM: chip id 107 Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM: features 0x2f Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM4345C0 Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Sep 29 11:19:20 garage kernel: snd-rpi-hifiberry-dacplus soc:sound: activating headphone amplifier Sep 29 11:19:20 garage systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Sep 29 11:19:20 garage kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Sep 29 11:19:20 garage kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Sep 29 11:19:20 garage kernel: usbcore: registered new interface driver brcmfmac Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM: features 0x2f Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Sep 29 11:19:20 garage kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Sep 29 11:19:21 garage kernel: tpa6130a2 1-0060: supply Vdd not found, using dummy regulator Sep 29 11:19:21 garage kernel: 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 29 11:19:21 garage systemd-udevd[363]: Using default interface naming scheme 'v240'. Sep 29 11:19:21 garage systemd-udevd[363]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 29 11:19:21 garage systemd[1]: Created slice system-bthelper.slice. Sep 29 11:19:21 garage systemd[1]: Condition check resulted in Huge Pages File System being skipped. Sep 29 11:19:21 garage systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Sep 29 11:19:21 garage systemd[1]: Starting Show Plymouth Boot Screen... Sep 29 11:19:21 garage systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 29 11:19:21 garage systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Sep 29 11:19:21 garage systemd[1]: Starting File System Check on /dev/disk/by-uuid/41CA-9A8B... Sep 29 11:19:21 garage systemd[1]: Starting Load/Save RF Kill Switch Status... Sep 29 11:19:21 garage systemd[1]: plymouth-start.service: Succeeded. Sep 29 11:19:21 garage systemd[1]: Started Show Plymouth Boot Screen. Sep 29 11:19:21 garage systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 29 11:19:21 garage systemd[1]: Started Load/Save RF Kill Switch Status. Sep 29 11:19:21 garage systemd[1]: Started File System Check Daemon to report status. Sep 29 11:19:21 garage systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Sep 29 11:19:21 garage systemd-fsck[543]: fsck.fat 4.1 (2017-01-24) Sep 29 11:19:21 garage systemd-fsck[543]: 0x41: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Sep 29 11:19:21 garage systemd-fsck[543]: Automatically removing dirty bit. Sep 29 11:19:21 garage systemd-fsck[543]: Performing changes. Sep 29 11:19:21 garage systemd-fsck[543]: /dev/mmcblk0p1: 447 files, 135821/184582 clusters Sep 29 11:19:21 garage systemd[1]: Started File System Check on /dev/disk/by-uuid/41CA-9A8B. Sep 29 11:19:21 garage systemd[1]: Mounting /boot... Sep 29 11:19:21 garage systemd[1]: Mounted /boot. Sep 29 11:19:21 garage systemd[1]: Reached target Local File Systems. Sep 29 11:19:21 garage systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Sep 29 11:19:21 garage systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Sep 29 11:19:21 garage systemd[1]: Starting Create Volatile Files and Directories... Sep 29 11:19:21 garage systemd[1]: Started ifup for wlan0. Sep 29 11:19:21 garage systemd[1]: Starting Preprocess NFS configuration... Sep 29 11:19:21 garage systemd[1]: Started ifup for eth0. Sep 29 11:19:21 garage systemd[1]: plymouth-read-write.service: Succeeded. Sep 29 11:19:21 garage systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Sep 29 11:19:21 garage systemd[1]: Received SIGRTMIN+20 from PID 214 (plymouthd). Sep 29 11:19:21 garage systemd[1]: nfs-config.service: Succeeded. Sep 29 11:19:21 garage systemd[1]: Started Preprocess NFS configuration. Sep 29 11:19:21 garage systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Sep 29 11:19:21 garage systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Sep 29 11:19:21 garage systemd[1]: Reached target NFS client services. Sep 29 11:19:21 garage systemd[1]: Started Helper to synchronize boot up for ifupdown. Sep 29 11:19:21 garage systemd[1]: Starting Raise network interfaces... Sep 29 11:19:21 garage systemd[1]: Started Create Volatile Files and Directories. Sep 29 11:19:21 garage systemd[1]: Starting Update UTMP about System Boot/Shutdown... Sep 29 11:19:21 garage systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Sep 29 11:19:21 garage systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Sep 29 11:19:21 garage systemd[1]: Starting RPC bind portmap service... Sep 29 11:19:21 garage kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Sep 29 11:19:21 garage kernel: bcmgenet fd580000.ethernet eth0: Link is Down Sep 29 11:19:21 garage systemd[1]: Started Update UTMP about System Boot/Shutdown. Sep 29 11:19:21 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 29 11:19:21 garage systemd[1]: Reached target System Initialization. Sep 29 11:19:22 garage systemd[1]: Listening on triggerhappy.socket. Sep 29 11:19:22 garage systemd[1]: Listening on D-Bus System Message Bus Socket. Sep 29 11:19:22 garage systemd[1]: apt-daily.timer: Not using persistent file timestamp Wed 2024-10-30 23:50:10 EDT as it is in the future. Sep 29 11:19:22 garage systemd[1]: Started Daily apt download activities. Sep 29 11:19:22 garage systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Thu 2024-10-31 06:02:10 EDT as it is in the future. Sep 29 11:19:22 garage systemd[1]: Started Daily apt upgrade and clean activities. Sep 29 11:19:22 garage systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Sep 29 11:19:22 garage systemd[1]: Reached target Sockets. Sep 29 11:19:22 garage systemd[1]: Reached target Basic System. Sep 29 11:19:22 garage systemd[1]: Starting Configure Bluetooth Modems connected by UART... Sep 29 11:19:22 garage systemd[1]: Started D-Bus System Message Bus. Sep 29 11:19:22 garage systemd[1]: Started volumio-remote-updater.service. Sep 29 11:19:22 garage systemd[1]: Started Volumio Log Rotation Service. Sep 29 11:19:22 garage systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Sep 29 11:19:22 garage systemd[1]: Starting Login Service... Sep 29 11:19:22 garage systemd[1]: Starting Wireless Services... Sep 29 11:19:22 garage systemd[1]: Started UPnP Renderer front-end to MPD. Sep 29 11:19:22 garage systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Sep 29 11:19:22 garage systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Sep 29 11:19:22 garage systemd[1]: Starting triggerhappy global hotkey daemon... Sep 29 11:19:22 garage systemd[1]: Started Volumio Iptables Module. Sep 29 11:19:22 garage systemd[1]: Starting WPA supplicant... Sep 29 11:19:22 garage systemd[1]: Started Daily Cleanup of Temporary Directories. Sep 29 11:19:22 garage systemd[1]: Reached target Timers. Sep 29 11:19:22 garage systemd[1]: Started Manage Sound Card State (restore and store). Sep 29 11:19:22 garage alsactl[682]: alsactl 1.1.8 daemon started Sep 29 11:19:22 garage systemd[1]: Starting Save/Restore Sound Card State... Sep 29 11:19:22 garage systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Sep 29 11:19:22 garage systemd[1]: Starting dhcpcd on all interfaces... Sep 29 11:19:22 garage systemd[1]: Started RPC bind portmap service. Sep 29 11:19:22 garage systemd[1]: hciuart.service: Succeeded. Sep 29 11:19:22 garage systemd[1]: Started Configure Bluetooth Modems connected by UART. Sep 29 11:19:22 garage thd[677]: Unable to parse trigger line: Sep 29 11:19:22 garage thd[677]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Sep 29 11:19:22 garage thd[677]: Unable to parse trigger line: Sep 29 11:19:22 garage thd[677]: Found socket passed from systemd Sep 29 11:19:22 garage systemd[1]: Started triggerhappy global hotkey daemon. Sep 29 11:19:22 garage ifup[576]: ifup: waiting for lock on /run/network/ifstate.wlan0 Sep 29 11:19:22 garage sh[554]: wlan0=wlan0 Sep 29 11:19:22 garage systemd[1]: Starting Raspberry Pi bluetooth helper... Sep 29 11:19:22 garage sh[556]: eth0=eth0 Sep 29 11:19:22 garage systemd[1]: Reached target Remote File Systems (Pre). Sep 29 11:19:22 garage systemd[1]: Reached target Remote File Systems. Sep 29 11:19:22 garage systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Sep 29 11:19:22 garage systemd-logind[668]: New seat seat0. Sep 29 11:19:22 garage systemd[1]: Reached target RPC Port Mapper. Sep 29 11:19:22 garage avahi-daemon[674]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Sep 29 11:19:22 garage avahi-daemon[674]: Successfully dropped root privileges. Sep 29 11:19:22 garage avahi-daemon[674]: avahi-daemon 0.7 starting up. Sep 29 11:19:22 garage systemd[1]: Started Save/Restore Sound Card State. Sep 29 11:19:22 garage systemd[1]: Reached target Sound Card. Sep 29 11:19:22 garage dhcpcd[687]: dev: loaded udev Sep 29 11:19:22 garage bthelper[694]: Raspberry Pi BDADDR already set Sep 29 11:19:23 garage kernel: 8021q: 802.1Q VLAN Support v1.8 Sep 29 11:19:23 garage dhcpcd[687]: forked to background, child pid 744 Sep 29 11:19:23 garage systemd[1]: Started dhcpcd on all interfaces. Sep 29 11:19:23 garage systemd[1]: Started Raspberry Pi bluetooth helper. Sep 29 11:19:23 garage avahi-daemon[674]: Successfully called chroot(). Sep 29 11:19:23 garage avahi-daemon[674]: Successfully dropped remaining capabilities. Sep 29 11:19:23 garage wpa_supplicant[681]: Successfully initialized wpa_supplicant Sep 29 11:19:23 garage avahi-daemon[674]: Loading service file /services/volumio.service. Sep 29 11:19:23 garage avahi-daemon[674]: Network interface enumeration completed. Sep 29 11:19:23 garage avahi-daemon[674]: Server startup complete. Host name is garage.local. Local service cookie is 3766929706. Sep 29 11:19:23 garage avahi-daemon[674]: Service "Garage" (/services/volumio.service) successfully established. Sep 29 11:19:23 garage systemd[1]: Started Raise network interfaces. Sep 29 11:19:23 garage systemd[1]: Started Login Service. Sep 29 11:19:23 garage systemd[1]: Started Avahi mDNS/DNS-SD Stack. Sep 29 11:19:23 garage systemd[1]: Started WPA supplicant. Sep 29 11:19:23 garage systemd[1]: Starting Bluetooth service... Sep 29 11:19:23 garage systemd[1]: Reached target Network. Sep 29 11:19:23 garage systemd[1]: Reached target Network is Online. Sep 29 11:19:23 garage systemd[1]: Starting LSB: Brings up/down network automatically... Sep 29 11:19:23 garage systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 29 11:19:23 garage volumio-remote-updater[656]: Error: No active session Sep 29 11:19:23 garage volumio-remote-updater[656]: [2024-09-29 11:19:23] [info] asio async_connect error: system:111 (Connection refused) Sep 29 11:19:23 garage volumio-remote-updater[656]: [2024-09-29 11:19:23] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 29 11:19:23 garage volumio-remote-updater[656]: [2024-09-29 11:19:23] [error] handle_connect error: Underlying Transport Error Sep 29 11:19:23 garage systemd[1]: Starting Permit User Sessions... Sep 29 11:19:23 garage systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Sep 29 11:19:23 garage systemd[1]: Starting Network Time Service... Sep 29 11:19:23 garage systemd[1]: Starting /etc/rc.local Compatibility... Sep 29 11:19:23 garage volumio[673]: Could not open config: /tmp/upmpdcli.conf Sep 29 11:19:23 garage systemd[1]: Starting OpenBSD Secure Shell server... Sep 29 11:19:24 garage systemd[1]: Starting Samba NMB Daemon... Sep 29 11:19:24 garage systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Sep 29 11:19:24 garage systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Sep 29 11:19:24 garage systemd[1]: Started Permit User Sessions. Sep 29 11:19:24 garage systemd[1]: Started /etc/rc.local Compatibility. Sep 29 11:19:24 garage bluetoothd[760]: Bluetooth daemon 5.50 Sep 29 11:19:24 garage bluetoothd[760]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Sep 29 11:19:24 garage bluetoothd[760]: Starting SDP server Sep 29 11:19:24 garage bluetoothd[760]: Excluding (cli) sap Sep 29 11:19:24 garage systemd[1]: Started Bluetooth service. Sep 29 11:19:24 garage systemd[1]: Reached target Bluetooth. Sep 29 11:19:24 garage systemd[1]: Starting Hold until boot process finishes up... Sep 29 11:19:24 garage dhcpcd-run-hooks[814]: wlan0: starting wpa_supplicant Sep 29 11:19:24 garage systemd[1]: Starting Terminate Plymouth Boot Screen... Sep 29 11:19:24 garage systemd[1]: iptables.service: Succeeded. Sep 29 11:19:24 garage loadcpufreq[708]: Loading cpufreq kernel modules...done (none). Sep 29 11:19:24 garage systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Sep 29 11:19:24 garage kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Sep 29 11:19:24 garage kernel: Bluetooth: BNEP filters: protocol multicast Sep 29 11:19:24 garage kernel: Bluetooth: BNEP socket layer initialized Sep 29 11:19:24 garage bluetoothd[760]: Bluetooth management interface 1.22 initialized Sep 29 11:19:24 garage dbus-daemon[650]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=760 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Sep 29 11:19:24 garage kernel: Bluetooth: MGMT ver 1.22 Sep 29 11:19:24 garage systemd[1]: plymouth-quit-wait.service: Succeeded. Sep 29 11:19:24 garage systemd[1]: Started Hold until boot process finishes up. Sep 29 11:19:24 garage systemd[1]: plymouth-quit.service: Succeeded. Sep 29 11:19:24 garage systemd[1]: Started Terminate Plymouth Boot Screen. Sep 29 11:19:24 garage systemd[1]: Received SIGRTMIN+21 from PID 214 (n/a). Sep 29 11:19:24 garage systemd[1]: Received SIGRTMIN+21 from PID 214 (n/a). Sep 29 11:19:24 garage ntpd[777]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 29 11:19:24 garage ntpd[777]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Sep 29 11:19:24 garage ntpd[826]: proto: precision = 2.093 usec (-19) Sep 29 11:19:24 garage ifplugd(eth0)[835]: ifplugd 0.28 initializing. Sep 29 11:19:24 garage ifplugd(eth0)[835]: Using interface eth0/E4:5F:01:02:5D:24 with driver (version: 6.1.69-v7l+) Sep 29 11:19:24 garage ifplugd(eth0)[835]: Using detection mode: SIOCETHTOOL Sep 29 11:19:24 garage ifplugd(eth0)[835]: Initialization complete, link beat not detected. Sep 29 11:19:24 garage bluetoothd[760]: Failed to set privacy: Rejected (0x0b) Sep 29 11:19:24 garage ntpd[826]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 29 11:19:24 garage ntpd[826]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 29 11:19:24 garage ntpd[826]: Listen and drop on 0 v6wildcard [::]:123 Sep 29 11:19:24 garage ntpd[826]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 29 11:19:24 garage ntpd[826]: Listen normally on 2 lo 127.0.0.1:123 Sep 29 11:19:24 garage ntpd[826]: Listening on routing socket on fd #19 for interface updates Sep 29 11:19:24 garage ntpd[826]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 29 11:19:24 garage ntpd[826]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 29 11:19:24 garage ifplugd[770]: Network Interface Plugging Daemon...start eth0...done. Sep 29 11:19:24 garage dhcpcd[744]: wlan0: connected to Access Point `' Sep 29 11:19:24 garage systemd[1]: Started LSB: Brings up/down network automatically. Sep 29 11:19:24 garage systemd[1]: Started Network Time Service. Sep 29 11:19:24 garage dhcpcd[744]: eth0: waiting for carrier Sep 29 11:19:24 garage dhcpcd[744]: wlan0: waiting for carrier Sep 29 11:19:24 garage systemd[1]: Starting Hostname Service... Sep 29 11:19:24 garage systemd[1]: Started Getty on tty1. Sep 29 11:19:24 garage systemd[1]: Reached target Login Prompts. Sep 29 11:19:24 garage systemd[1]: Starting LSB: set CPUFreq kernel parameters... Sep 29 11:19:24 garage sshd[854]: Server listening on 0.0.0.0 port 22. Sep 29 11:19:24 garage sshd[854]: Server listening on :: port 22. Sep 29 11:19:24 garage systemd[1]: Started OpenBSD Secure Shell server. Sep 29 11:19:25 garage dbus-daemon[650]: [system] Successfully activated service 'org.freedesktop.hostname1' Sep 29 11:19:25 garage systemd[1]: Started Hostname Service. Sep 29 11:19:25 garage cpufrequtils[857]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Sep 29 11:19:25 garage systemd[1]: Started LSB: set CPUFreq kernel parameters. Sep 29 11:19:25 garage nmbd[808]: [2024/09/29 11:19:25.431690, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Sep 29 11:19:25 garage nmbd[808]: started asyncdns process 870 Sep 29 11:19:25 garage nmbd[808]: [2024/09/29 11:19:25.433734, 0] ../lib/util/become_daemon.c:149(daemon_status) Sep 29 11:19:25 garage nmbd[808]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Sep 29 11:19:25 garage nmbd[808]: [2024/09/29 11:19:25.433929, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Sep 29 11:19:25 garage nmbd[808]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Sep 29 11:19:25 garage ntpd[826]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 29 11:19:25 garage haveged[602]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Sep 29 11:19:25 garage haveged[602]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Sep 29 11:19:25 garage haveged[602]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99837 Sep 29 11:19:25 garage haveged[602]: haveged: fills: 0, generated: 0 Sep 29 11:19:25 garage wireless.js[669]: Cleaning previous... Sep 29 11:19:25 garage sudo[878]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 29 11:19:25 garage sudo[878]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:25 garage sudo[878]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:25 garage sudo[880]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 29 11:19:25 garage sudo[880]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:26 garage systemd[1]: systemd-rfkill.service: Succeeded. Sep 29 11:19:26 garage sudo[880]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:26 garage wireless.js[669]: Stopped aP Sep 29 11:19:26 garage sudo[887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 29 11:19:26 garage sudo[887]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:26 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 29 11:19:26 garage ntpd[826]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 29 11:19:26 garage sudo[887]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:26 garage sudo[889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Sep 29 11:19:26 garage sudo[889]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:26 garage sudo[889]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:26 garage sudo[896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 29 11:19:26 garage sudo[896]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:26 garage sudo[896]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:26 garage sudo[898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Sep 29 11:19:26 garage sudo[898]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:27 garage ntpd[826]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Sep 29 11:19:28 garage bthelper[694]: Changing power off succeeded Sep 29 11:19:28 garage bthelper[694]: [CHG] Controller E4:5F:01:02:5D:28 Class: 0x0000041c Sep 29 11:19:28 garage bthelper[694]: Changing power on succeeded Sep 29 11:19:28 garage ntpd[826]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 29 11:19:28 garage volumio-remote-updater[656]: [2024-09-29 11:19:28] [info] asio async_connect error: system:111 (Connection refused) Sep 29 11:19:28 garage volumio-remote-updater[656]: [2024-09-29 11:19:28] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 29 11:19:28 garage volumio-remote-updater[656]: [2024-09-29 11:19:28] [error] handle_connect error: Underlying Transport Error Sep 29 11:19:29 garage sudo[898]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:29 garage wireless.js[669]: SETTING APPROPRIATE REG DOMAIN: US Sep 29 11:19:29 garage sudo[910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 29 11:19:29 garage sudo[910]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:29 garage sudo[910]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:29 garage sudo[912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Sep 29 11:19:29 garage sudo[912]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:29 garage sudo[912]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:29 garage wireless.js[669]: SUCCESSFULLY SET NEW REGDOMAIN: US Sep 29 11:19:29 garage wireless.js[669]: Start wireless flow Sep 29 11:19:29 garage wireless.js[669]: Stopped hotspot (if there).. Sep 29 11:19:29 garage sudo[917]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 29 11:19:29 garage sudo[917]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:29 garage sudo[917]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:29 garage sudo[919]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 29 11:19:29 garage sudo[919]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:30 garage sudo[919]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:30 garage wireless.js[669]: DHCP IP Sep 29 11:19:30 garage wireless.js[669]: Start ap Sep 29 11:19:30 garage wpa_supplicant[921]: Successfully initialized wpa_supplicant Sep 29 11:19:30 garage sudo[922]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Sep 29 11:19:30 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 29 11:19:30 garage sudo[922]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:30 garage dhcpcd[923]: sending commands to master dhcpcd process Sep 29 11:19:30 garage dhcpcd[744]: control command: /sbin/dhcpcd Sep 29 11:19:30 garage sudo[922]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:30 garage dhcpcd[744]: lo: carrier acquired Sep 29 11:19:30 garage dhcpcd[744]: DUID 00:01:00:01:2e:31:51:de:e4:5f:01:02:5d:24 Sep 29 11:19:30 garage dhcpcd[744]: lo: IAID 6c:6f:00:00 Sep 29 11:19:30 garage dhcpcd[744]: lo: ipv6_start: Operation not supported Sep 29 11:19:30 garage dhcpcd[744]: lo: using static address 127.0.0.1/8 Sep 29 11:19:30 garage dhcpcd[744]: lo: adding route to 127.0.0.0/8 Sep 29 11:19:30 garage dhcpcd[744]: arp_announce: Invalid argument Sep 29 11:19:31 garage wireless.js[669]: trying... Sep 29 11:19:31 garage sudo[953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:31 garage sudo[953]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:31 garage sudo[953]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:32 garage wireless.js[669]: trying... Sep 29 11:19:32 garage sudo[956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:32 garage sudo[956]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:32 garage sudo[956]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:33 garage wpa_supplicant[932]: wlan0: Trying to associate with SSID 'WLAN2' Sep 29 11:19:33 garage wireless.js[669]: trying... Sep 29 11:19:33 garage sudo[959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:33 garage sudo[959]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:33 garage sudo[959]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:34 garage wireless.js[669]: trying... Sep 29 11:19:34 garage sudo[962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:34 garage sudo[962]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:34 garage sudo[962]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:35 garage wireless.js[669]: trying... Sep 29 11:19:35 garage sudo[965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:35 garage sudo[965]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:35 garage sudo[965]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:36 garage wpa_supplicant[932]: wlan0: Associated with 7c:2e:bd:97:f3:47 Sep 29 11:19:36 garage wpa_supplicant[932]: wlan0: CTRL-EVENT-CONNECTED - Connection to 7c:2e:bd:97:f3:47 completed [id=0 id_str=] Sep 29 11:19:36 garage dhcpcd[744]: wlan0: carrier acquired Sep 29 11:19:36 garage wpa_supplicant[932]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 29 11:19:36 garage dhcpcd[744]: wlan0: connected to Access Point `WLAN2' Sep 29 11:19:36 garage wpa_supplicant[932]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Sep 29 11:19:36 garage dhcpcd[744]: wlan0: IAID 01:02:5d:26 Sep 29 11:19:36 garage dhcpcd[744]: wlan0: adding address fe80::e65f:1ff:fe02:5d26 Sep 29 11:19:36 garage dhcpcd[744]: ipv6_addaddr1: Permission denied Sep 29 11:19:36 garage wireless.js[669]: trying... Sep 29 11:19:36 garage sudo[969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:36 garage sudo[969]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:36 garage sudo[969]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:36 garage dhcpcd[744]: wlan0: soliciting an IPv6 router Sep 29 11:19:36 garage volumio-remote-updater[656]: [2024-09-29 11:19:36] [info] asio async_connect error: system:111 (Connection refused) Sep 29 11:19:36 garage volumio-remote-updater[656]: [2024-09-29 11:19:36] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 29 11:19:36 garage volumio-remote-updater[656]: [2024-09-29 11:19:36] [error] handle_connect error: Underlying Transport Error Sep 29 11:19:36 garage dhcpcd[744]: wlan0: rebinding lease of 192.168.86.47 Sep 29 11:19:37 garage dhcpcd[744]: wlan0: probing address 192.168.86.47/24 Sep 29 11:19:37 garage wireless.js[669]: trying... Sep 29 11:19:37 garage sudo[972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:37 garage sudo[972]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:37 garage sudo[972]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:38 garage wireless.js[669]: trying... Sep 29 11:19:38 garage sudo[975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:38 garage sudo[975]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:38 garage sudo[975]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:39 garage wireless.js[669]: trying... Sep 29 11:19:39 garage sudo[978]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:39 garage sudo[978]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:39 garage sudo[978]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:40 garage wireless.js[669]: trying... Sep 29 11:19:40 garage sudo[981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:40 garage sudo[981]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:40 garage sudo[981]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:41 garage wireless.js[669]: trying... Sep 29 11:19:41 garage sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:41 garage sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:41 garage sudo[984]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:41 garage dhcpcd[744]: wlan0: leased 192.168.86.47 for 86400 seconds Sep 29 11:19:41 garage avahi-daemon[674]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.86.47. Sep 29 11:19:41 garage avahi-daemon[674]: New relevant interface wlan0.IPv4 for mDNS. Sep 29 11:19:41 garage dhcpcd[744]: wlan0: adding route to 192.168.86.0/24 Sep 29 11:19:41 garage avahi-daemon[674]: Registering new address record for 192.168.86.47 on wlan0.IPv4. Sep 29 11:19:41 garage dhcpcd[744]: wlan0: adding default route via 192.168.86.1 Sep 29 11:19:42 garage wireless.js[669]: trying... Sep 29 11:19:42 garage sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 29 11:19:42 garage sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:42 garage sudo[1008]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:42 garage wireless.js[669]: Connected to: ----WLAN2 Sep 29 11:19:42 garage wireless.js[669]: ---- Sep 29 11:19:42 garage sudo[1011]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 29 11:19:42 garage sudo[1011]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:42 garage sudo[1011]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:42 garage wireless.js[669]: ... joined AP, wlan0 IPv4 is 192.168.86.47, ipV6 is undefined Sep 29 11:19:42 garage wireless.js[669]: It's done! AP Sep 29 11:19:42 garage systemd[1]: Started Wireless Services. Sep 29 11:19:42 garage systemd[1]: Started Volumio Backend Module. Sep 29 11:19:42 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 29 11:19:42 garage systemd[1]: Started Volumio Cpu Tweaker. Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: Setting RT Priority for mpd Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: pid 35's current scheduling policy: SCHED_OTHER Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: pid 35's current scheduling priority: 0 Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: Setting MPD Affinity Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: pid 3's current affinity mask: f Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Sep 29 11:19:42 garage volumio-cpu-tweak[1017]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Sep 29 11:19:42 garage systemd[1]: volumio_cpu_tweak.service: Succeeded. Sep 29 11:19:43 garage ntpd[826]: Listen normally on 3 wlan0 192.168.86.47:123 Sep 29 11:19:43 garage ntpd[826]: new interface(s) found: waking up resolver Sep 29 11:19:44 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:44 garage volumio[1016]: info: ----- Volumio3 ---- Sep 29 11:19:44 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:44 garage volumio[1016]: info: ----- System startup ---- Sep 29 11:19:44 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:44 garage volumio[1016]: info: MYVOLUMIO Environment detected Sep 29 11:19:44 garage volumio[1016]: info: Plugin folders cleanup Sep 29 11:19:44 garage volumio[1016]: info: Scanning into folder /volumio/app/plugins/ Sep 29 11:19:44 garage volumio[1016]: info: Scanning category audio_interface Sep 29 11:19:44 garage volumio[1016]: info: Scanning category miscellanea Sep 29 11:19:44 garage volumio[1016]: info: Scanning category music_service Sep 29 11:19:44 garage volumio[1016]: info: Scanning category plugins.json Sep 29 11:19:44 garage volumio[1016]: info: Scanning category system_controller Sep 29 11:19:44 garage volumio[1016]: info: Scanning category user_interface Sep 29 11:19:44 garage volumio[1016]: info: Scanning into folder /data/plugins/ Sep 29 11:19:44 garage volumio[1016]: info: Scanning category music_service Sep 29 11:19:44 garage volumio[1016]: info: Plugin folders cleanup completed Sep 29 11:19:44 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:44 garage volumio[1016]: info: ----- Core plugins startup ---- Sep 29 11:19:44 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:44 garage volumio[1016]: info: Loading plugins from folder /volumio/app/plugins/ Sep 29 11:19:44 garage volumio[1016]: info: Adding plugin upnp to MyMusic Plugins Sep 29 11:19:44 garage volumio[1016]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 29 11:19:44 garage volumio[1016]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 29 11:19:44 garage volumio[1016]: info: Loading plugins from folder /data/plugins/ Sep 29 11:19:44 garage volumio[1016]: info: Loading plugin "system"... Sep 29 11:19:44 garage volumio[1016]: info: Loading plugin "appearance"... Sep 29 11:19:45 garage nmbd[808]: [2024/09/29 11:19:45.437944, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 29 11:19:45 garage nmbd[808]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Sep 29 11:19:45 garage systemd[1]: Started Samba NMB Daemon. Sep 29 11:19:45 garage systemd[1]: Starting Samba Winbind Daemon... Sep 29 11:19:45 garage winbindd[1046]: [2024/09/29 11:19:45.721136, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Sep 29 11:19:45 garage winbindd[1046]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Sep 29 11:19:45 garage winbindd[1046]: [2024/09/29 11:19:45.827711, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 29 11:19:45 garage winbindd[1046]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Sep 29 11:19:45 garage systemd[1]: Started Samba Winbind Daemon. Sep 29 11:19:45 garage systemd[1]: Starting Samba SMB Daemon... Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "network"... Sep 29 11:19:46 garage volumio[1016]: info: Refreshing Cached IP Addresses Sep 29 11:19:46 garage sudo[1053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 29 11:19:46 garage sudo[1053]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:46 garage sudo[1053]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:46 garage sudo[1055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "services"... Sep 29 11:19:46 garage sudo[1055]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:46 garage sudo[1055]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "alsa_controller"... Sep 29 11:19:46 garage sudo[1059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 29 11:19:46 garage sudo[1059]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:46 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "wizard"... Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "networkfs"... Sep 29 11:19:46 garage winbindd[1046]: [2024/09/29 11:19:46.236728, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Sep 29 11:19:46 garage winbindd[1046]: res_names->count = 3, expected 4 Sep 29 11:19:46 garage smbd[1051]: [2024/09/29 11:19:46.255790, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 29 11:19:46 garage systemd[1]: Started Samba SMB Daemon. Sep 29 11:19:46 garage smbd[1051]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Sep 29 11:19:46 garage systemd[1]: Reached target Multi-User System. Sep 29 11:19:46 garage systemd[1]: Reached target Graphical Interface. Sep 29 11:19:46 garage volumio-remote-updater[656]: [2024-09-29 11:19:46] [connect] Successful connection Sep 29 11:19:46 garage volumio[1016]: info: Starting Udev Watcher for removable devices Sep 29 11:19:46 garage volumio[1016]: info: Ignoring mount for partition: boot Sep 29 11:19:46 garage volumio[1016]: info: Ignoring mount for partition: volumio Sep 29 11:19:46 garage volumio[1016]: info: Ignoring mount for partition: volumio_data Sep 29 11:19:46 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "volumio_command_line_client"... Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "upnp"... Sep 29 11:19:46 garage volumio[1016]: info: [1727623186342] Starting Upmpd Daemon Sep 29 11:19:46 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "my_music"... Sep 29 11:19:46 garage sudo[1074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.127/Music/ /mnt/NAS/Music Sep 29 11:19:46 garage systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 29 11:19:46 garage sudo[1074]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "mpd"... Sep 29 11:19:46 garage systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 29 11:19:46 garage systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 29 11:19:46 garage systemd[1]: Startup finished in 14.425s (kernel) + 30.665s (userspace) = 45.091s. Sep 29 11:19:46 garage kernel: Key type cifs.spnego registered Sep 29 11:19:46 garage kernel: Key type cifs.idmap registered Sep 29 11:19:46 garage kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Sep 29 11:19:46 garage kernel: CIFS: Attempting to mount \\192.168.1.127\Music Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "upnp_browser"... Sep 29 11:19:46 garage volumio[1016]: info: Loading plugin "alarm-clock"... Sep 29 11:19:47 garage volumio[1016]: info: Loading plugin "airplay_emulation"... Sep 29 11:19:47 garage volumio[1016]: info: Starting Shairport Sync Sep 29 11:19:47 garage volumio[1016]: info: Loading plugin "last_100"... Sep 29 11:19:47 garage volumio[1016]: info: Loading plugin "webradio"... Sep 29 11:19:47 garage volumio[1016]: info: Loading plugin "i2s_dacs"... Sep 29 11:19:47 garage volumio[1016]: info: Loading plugin "volumiodiscovery"... Sep 29 11:19:47 garage volumio[1016]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 29 11:19:47 garage volumio[1016]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 29 11:19:47 garage node[1016]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 29 11:19:47 garage volumio[1016]: *** WARNING *** For more information see Sep 29 11:19:47 garage volumio[1016]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 29 11:19:47 garage volumio[1016]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 29 11:19:47 garage volumio[1016]: *** WARNING *** For more information see Sep 29 11:19:47 garage node[1016]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 29 11:19:47 garage node[1016]: *** WARNING *** For more information see Sep 29 11:19:47 garage node[1016]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 29 11:19:47 garage node[1016]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 29 11:19:47 garage node[1016]: *** WARNING *** For more information see Sep 29 11:19:47 garage volumio[1016]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 29 11:19:47 garage volumio[1016]: info: Discovery: Started advertising with name: Garage Sep 29 11:19:47 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 29 11:19:47 garage volumio[1016]: info: Loading plugin "spop"... Sep 29 11:19:48 garage sudo[1074]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:48 garage volumio[1016]: info: Loading plugin "ytmusic"... Sep 29 11:19:49 garage volumio[1016]: info: Loading plugin "outputs"... Sep 29 11:19:49 garage volumio[1016]: info: Loading plugin "albumart"... Sep 29 11:19:49 garage volumio[1016]: info: Plugin example_plugin is not enabled Sep 29 11:19:49 garage volumio[1016]: info: Loading plugin "inputs"... Sep 29 11:19:49 garage volumio[1016]: info: Loading plugin "updater_comm"... Sep 29 11:19:49 garage volumio[1016]: info: Plugin mpdemulation is not enabled Sep 29 11:19:49 garage volumio[1016]: info: Loading plugin "rest_api"... Sep 29 11:19:49 garage volumio[1016]: info: Loading plugin "websocket"... Sep 29 11:19:49 garage volumio[1016]: info: Starting Socket.io Server version 2.3.0 Sep 29 11:19:49 garage volumio[1016]: info: Loading i18n strings for locale en Sep 29 11:19:49 garage volumio[1016]: Forking 3 albumart workers Sep 29 11:19:49 garage volumio[1016]: Updating browse sources language Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::initPlayerControls Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 29 11:19:49 garage volumio[1016]: Express server listening on port 3000 Sep 29 11:19:49 garage volumio[1016]: [Metrics] WebUI: 6s 440.84ms Sep 29 11:19:49 garage volumio[1016]: info: CoreStateMachine::resetVolumioState Sep 29 11:19:49 garage volumio[1016]: info: CoreStateMachine::getcurrentVolume Sep 29 11:19:49 garage volumio[1016]: info: CoreCommandRouter::volumioRetrievevolume Sep 29 11:19:49 garage volumio[1016]: info: Cannot read play queue from file Sep 29 11:19:50 garage volumio-remote-updater[656]: [2024-09-29 11:19:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1727623186 101 Sep 29 11:19:50 garage volumio[1016]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Sep 29 11:19:50 garage volumio[1016]: verbose: New Socket.io Connection to 192.168.86.47:3000 from 192.168.86.24 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 29 11:19:50 garage volumio[1016]: verbose: New Socket.io Connection to 192.168.86.47:3000 from 192.168.86.57 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Sep 29 11:19:50 garage volumio[1016]: verbose: New Socket.io Connection to 192.168.86.47:3000 from 192.168.86.57 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:50 garage volumio[1016]: Starting albumart workers Sep 29 11:19:50 garage volumio[1016]: info: Setting Device type: Raspberry PI Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::setRepeat null single undefined Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::pushState Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioPushState Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::setRandom null Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::pushState Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioPushState Sep 29 11:19:50 garage volumio[1016]: info: VolumeController:: Volume=100 Mute =false Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::pushState Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioPushState Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::updateTrackBlock Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrackBlock Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioRetrievevolume Sep 29 11:19:50 garage volumio[1016]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 29 11:19:50 garage volumio[1016]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Sep 29 11:19:50 garage volumio[1016]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 29 11:19:50 garage volumio[1016]: Starting albumart workers Sep 29 11:19:50 garage volumio[1016]: info: Completed loading Core Plugins Sep 29 11:19:50 garage volumio[1016]: info: Preparing to generate the ALSA configuration file Sep 29 11:19:50 garage volumio[1016]: Starting albumart workers Sep 29 11:19:50 garage sudo[1059]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Sep 29 11:19:50 garage volumio[1016]: info: Discovery: adding 4970146e-0e96-44b8-b0ae-8af58ba9d6fb Sep 29 11:19:50 garage volumio[1016]: info: Discovery: Found device Garage Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioGetState Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioGetState Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:50 garage volumio[1016]: info: VolumeController:: Volume=100 Mute =false Sep 29 11:19:50 garage volumio[1016]: info: CoreStateMachine::pushState Sep 29 11:19:50 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioPushState Sep 29 11:19:50 garage volumio[1016]: info: Asound.conf file written Sep 29 11:19:50 garage sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 29 11:19:50 garage sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage sudo[1142]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:50 garage volumio[1016]: info: Output device has changed, restarting MPD Sep 29 11:19:50 garage sudo[1147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 29 11:19:50 garage sudo[1147]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage volumio[1016]: info: Output device has changed, restarting Shairport Sync Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:50 garage sudo[1147]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:50 garage sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 29 11:19:50 garage sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage volumio[1016]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 29 11:19:50 garage volumio[1016]: info: ___________ START PLUGINS ___________ Sep 29 11:19:50 garage volumio[1016]: info: ControllerMpd::onStart: Initializing MPD Sep 29 11:19:50 garage volumio[1016]: info: Creating MPD Configuration file Sep 29 11:19:50 garage systemd[1]: Listening on mpd.socket. Sep 29 11:19:50 garage systemd[1]: Starting Music Player Daemon... Sep 29 11:19:50 garage sudo[1174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 29 11:19:50 garage sudo[1174]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 29 11:19:50 garage volumio[1016]: info: [1727623190744] CoreMusicLibrary::Adding element Media Servers Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 29 11:19:50 garage sudo[1174]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:50 garage sudo[1177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 29 11:19:50 garage sudo[1177]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:50 garage sudo[1173]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 29 11:19:50 garage sudo[1173]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage sudo[1173]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:50 garage systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 29 11:19:50 garage systemd[1]: mpd.service: Succeeded. Sep 29 11:19:50 garage systemd[1]: Stopped Music Player Daemon. Sep 29 11:19:50 garage systemd[1]: Starting Music Player Daemon... Sep 29 11:19:50 garage volumio[1016]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 29 11:19:50 garage volumio[1016]: info: [1727623190855] CoreMusicLibrary::Adding element Last_100 Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 29 11:19:50 garage volumio[1016]: info: [1727623190858] CoreMusicLibrary::Adding element Webradio Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 29 11:19:50 garage volumio[1016]: info: Initializing BBC Radios Sep 29 11:19:50 garage sudo[1187]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 29 11:19:50 garage sudo[1187]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:50 garage sudo[1187]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Sep 29 11:19:50 garage sudo[1187]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: Creating Spotify config file Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 29 11:19:50 garage volumio[1016]: info: [1727623190999] CoreMusicLibrary::Adding element YouTube Music Sep 29 11:19:50 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 29 11:19:51 garage volumio[1016]: Cannot find translation for source YouTube Music Sep 29 11:19:51 garage volumio[1016]: info: Volumio Calling Home Sep 29 11:19:51 garage volumio[1016]: info: MPD Permissions set Sep 29 11:19:51 garage volumio[1016]: info: MPD Permissions set Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::volumioGetState Sep 29 11:19:51 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:51 garage volumio[1016]: info: Spotify config file written Sep 29 11:19:51 garage volumio[1016]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Sep 29 11:19:51 garage sudo[1211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:51 garage sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 29 11:19:51 garage volumio[1016]: info: No need to fix Spotify hosts Sep 29 11:19:51 garage volumio[1016]: info: Starting Shairport Sync Sep 29 11:19:51 garage systemd[1]: Started go-librespot Daemon. Sep 29 11:19:51 garage go-librespot[1218]: Librespot-go daemon starting... Sep 29 11:19:51 garage volumio[1016]: info: Starting Shairport Sync Sep 29 11:19:51 garage sudo[1211]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:51 garage sudo[1225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 29 11:19:51 garage volumio[1016]: info: Starting Shairport Sync Sep 29 11:19:51 garage sudo[1225]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:51 garage sudo[1227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 29 11:19:51 garage volumio[1016]: info: CoreCommandRouter::volumioGetState Sep 29 11:19:51 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:51 garage sudo[1227]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:51 garage systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 29 11:19:51 garage systemd[1]: shairport-sync.service: Succeeded. Sep 29 11:19:51 garage systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 29 11:19:51 garage sudo[1230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 29 11:19:51 garage sudo[1230]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:51 garage systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 29 11:19:51 garage volumio[1016]: info: Discovery: adding 2610c474-41de-4002-ac22-909a187671dd Sep 29 11:19:51 garage volumio[1016]: info: Discovery: Found device Living Room Sep 29 11:19:51 garage sudo[1225]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:51 garage volumio[1016]: info: Discovery: Connecting to remote: 192.168.86.24 Sep 29 11:19:51 garage systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 29 11:19:51 garage systemd[1]: shairport-sync.service: Succeeded. Sep 29 11:19:51 garage systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 29 11:19:51 garage systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 29 11:19:51 garage sudo[1230]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:51 garage sudo[1227]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:51 garage volumio[1016]: info: Discovery: adding e126e053-f69f-468a-8f32-22a137163f3c Sep 29 11:19:51 garage volumio[1016]: info: Discovery: Found device Family-Room Sep 29 11:19:51 garage volumio[1016]: info: Discovery: Connecting to remote: 192.168.86.57 Sep 29 11:19:51 garage volumio[1016]: info: An error occurred while refreshing Spotify Token Error: certificate is not yet valid Sep 29 11:19:51 garage volumio[1016]: info: Shairport-Sync Started Sep 29 11:19:51 garage volumio[1016]: Error adding Membership: Error: addMembership EINVAL Sep 29 11:19:51 garage volumio[1016]: info: Shairport-Sync Started Sep 29 11:19:51 garage volumio[1016]: info: Volumio called home Sep 29 11:19:51 garage volumio[1016]: info: Shairport-Sync Started Sep 29 11:19:51 garage volumio[1016]: info: Discovery: Connected to remote: 192.168.86.24 Sep 29 11:19:51 garage volumio[1016]: info: Discovery: Connected to remote: 192.168.86.57 Sep 29 11:19:51 garage systemd[1]: systemd-fsckd.service: Succeeded. Sep 29 11:19:51 garage go-librespot[1218]: time="2024-09-29T11:19:51-04:00" level=info msg="generated new device id: 9e5c49f257932a56fea088456b5dcbefe10470d0" Sep 29 11:19:51 garage go-librespot[1218]: time="2024-09-29T11:19:51-04:00" level=debug msg="stored credentials found for paulurfi" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="zeroconf server listening on port 38737" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="obtained new client token: AADLOPB7tYKdtDVlpbI/YdCJY+dkKYhpQuKu9y38qMVJRFQjcIzNKOnrA0IToPOlQXlGdonyZjWX3ajvz6ELvyafX0mzxULuu0gP+QLafwJoSSQcFuFDxXbEEB/oAswCIO/LlAPGz0ivNe6wiOQh27qTD3HOFT9YfQPbVjvhi1aYHJupraF/fb+GgWZVZOng6LyxiPNFkVob3kUKH5GyMBjler93i5Ki5ekeIbKoahrOl1JDYy5fEWIXGAeK" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=info msg="connected to ap-gue1.spotify.com:4070" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="completed keyexchange" Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="completed challenge" Sep 29 11:19:52 garage mpd[1196]: Sep 29 11:19 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 29 11:19:52 garage go-librespot[1218]: time="2024-09-29T11:19:52-04:00" level=debug msg="authenticated as paulurfi" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="authenticated as paulurfi" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="dealer connection opened" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="initializing zeroconf session, username: paulurfi" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="autoplay enabled: false" Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="received connection id: YjkyMTQ3MzMtN2MyYy00NzFkLTgzNDEtMTYwY2RkYThlZGQxK2RlYWxlcit0Y3A6Ly8wYWNiZjgxMS5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArQjQ5QzlDRUQwNTM5QUZFQUMwMDgzMTU4RUIyQTg1RUYwQkU2QkExREM1RUE4REE3RjEzMjk4QTE5RjMyMTIxOA==" Sep 29 11:19:53 garage systemd[1]: Started Music Player Daemon. Sep 29 11:19:53 garage sudo[1177]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:53 garage sudo[1151]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:53 garage volumio[1016]: info: Completed starting Core Plugins Sep 29 11:19:53 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:53 garage volumio[1016]: info: ----- MyVolumio plugins startup ---- Sep 29 11:19:53 garage volumio[1016]: info: ------------------------------------------- Sep 29 11:19:53 garage volumio[1016]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 29 11:19:53 garage volumio[1016]: error: MPD error: The expression evaluated to a falsy value: Sep 29 11:19:53 garage volumio[1016]: assert.ok(self.idling) Sep 29 11:19:53 garage volumio[1016]: error: The expression evaluated to a falsy value: Sep 29 11:19:53 garage volumio[1016]: assert.ok(self.idling) Sep 29 11:19:53 garage volumio[1016]: info: MPD running with PID1196 Sep 29 11:19:53 garage volumio[1016]: ,establishing connection Sep 29 11:19:53 garage volumio[1016]: error: MPD error: The expression evaluated to a falsy value: Sep 29 11:19:53 garage volumio[1016]: assert.ok(self.idling) Sep 29 11:19:53 garage volumio[1016]: error: The expression evaluated to a falsy value: Sep 29 11:19:53 garage volumio[1016]: assert.ok(self.idling) Sep 29 11:19:53 garage volumio[1016]: error: updateQueue error: null Sep 29 11:19:53 garage go-librespot[1218]: time="2024-09-29T11:19:53-04:00" level=debug msg="put connect state because NEW_DEVICE" Sep 29 11:19:54 garage volumio[1016]: info: go-librespot daemon successfully initialized Sep 29 11:19:55 garage systemd[1]: systemd-hostnamed.service: Succeeded. Sep 29 11:19:56 garage sudo[1251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 29 11:19:56 garage sudo[1251]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:56 garage sudo[1251]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:56 garage sudo[1253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 29 11:19:56 garage sudo[1253]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:56 garage sudo[1253]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:56 garage sudo[1257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 29 11:19:56 garage sudo[1257]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 29 11:19:56 garage systemd[1]: Started UPnP Renderer front-end to MPD. Sep 29 11:19:56 garage sudo[1257]: pam_unix(sudo:session): session closed for user root Sep 29 11:19:56 garage volumio[1016]: info: Upmpdcli Daemon Started Sep 29 11:19:56 garage volumio[1259]: Generating RSA private key, 4096 bit long modulus (2 primes) Sep 29 11:19:56 garage go-librespot[1218]: time="2024-09-29T11:19:56-04:00" level=debug msg="handling transfer player command from 4cd03b3844dfcad7e704b57b2e6b66c9c7ec77ef" Sep 29 11:19:56 garage go-librespot[1218]: time="2024-09-29T11:19:56-04:00" level=debug msg="resolved context of track" uri="spotify:playlist:2bWtVAl9VX45x9gAUPiVOF" Sep 29 11:19:56 garage go-librespot[1218]: time="2024-09-29T11:19:56-04:00" level=trace msg="fetched new page 0 with 150 items (list: 150)" uri="spotify:playlist:2bWtVAl9VX45x9gAUPiVOF" Sep 29 11:19:56 garage go-librespot[1218]: time="2024-09-29T11:19:56-04:00" level=debug msg="loading track (paused: false, position: -2785849996ms)" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=trace msg="emitting websocket event: will_play" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="selected format OGG_VORBIS_320 (0a6538f534c885c729afd0b57ea525d0e673cc32)" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="requested aes key for file 0a6538f534c885c729afd0b57ea525d0e673cc32, gid: 0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1351" Sep 29 11:19:57 garage volumio[1016]: info: Initializing connection to go-librespot Websocket Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="new websocket client" Sep 29 11:19:57 garage volumio[1016]: info: Connection to go-librespot Websocket established Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="fetched first chunk of 15, total size is 7636880 bytes" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:57 garage kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=debug msg="created new output device" Sep 29 11:19:57 garage go-librespot[1218]: time="2024-09-29T11:19:57-04:00" level=info msg="loaded track \"Monster Mash\" (paused: false, position: -2785849996ms, duration: 192040ms, prefetched: false)" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=trace msg="scheduling prefetch in 161s" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=trace msg="emitting websocket event: metadata" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=trace msg="emitting websocket event: active" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="sending successful reply for dealer request" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 29 11:19:58 garage volumio[1016]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0xxZY5C9xxij3D1HkzbnfC","name":"Monster Mash","artist_names":["Bobby \"Boris\" Pickett","The Crypt-Kickers"],"album_name":"The Original Monster Mash","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02edf6710f9c0cd81e37fcaf3d","position":-2785849996,"duration":192040,"release_date":"year:1962","track_number":1,"disc_number":1}} Sep 29 11:19:58 garage volumio[1016]: SPOTIFY: received: {"type":"active","data":null} Sep 29 11:19:58 garage volumio[1016]: info: Aligning Spotify Volume to Volumio Volume Sep 29 11:19:58 garage volumio[1016]: info: CoreCommandRouter::volumioGetState Sep 29 11:19:58 garage volumio[1016]: info: CorePlayQueue::getTrack 0 Sep 29 11:19:58 garage volumio[1016]: info: Setting Spotify Volume from Volumio: 100 Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:0xxZY5C9xxij3D1HkzbnfC" Sep 29 11:19:58 garage go-librespot[1218]: time="2024-09-29T11:19:58-04:00" level=trace msg="emitting websocket event: playing" Sep 29 11:19:58 garage volumio[1016]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0xxZY5C9xxij3D1HkzbnfC","play_origin":"playlist/ondemand"}} Sep 29 11:19:58 garage volumio[1016]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 29 11:19:58 garage volumio[1016]: TypeError: Cannot read property 'service' of undefined Sep 29 11:19:58 garage volumio[1016]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Sep 29 11:19:58 garage volumio[1016]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Sep 29 11:19:58 garage volumio[1016]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Sep 29 11:19:58 garage volumio[1016]: at WebSocket.emit (events.js:315:20) Sep 29 11:19:58 garage volumio[1016]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Sep 29 11:19:58 garage volumio[1016]: at Receiver.emit (events.js:315:20) Sep 29 11:19:58 garage volumio[1016]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Sep 29 11:19:58 garage volumio[1016]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Sep 29 11:19:58 garage volumio[1016]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Sep 29 11:19:58 garage volumio[1016]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Sep 29 11:19:58 garage volumio[1016]: at writeOrBuffer (internal/streams/writable.js:358:12) Sep 29 11:19:58 garage volumio[1016]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Sep 29 11:19:58 garage volumio[1016]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Sep 29 11:19:58 garage volumio[1016]: at Socket.emit (events.js:315:20) Sep 29 11:19:58 garage volumio[1016]: at addChunk (internal/streams/readable.js:309:12) Sep 29 11:19:58 garage volumio[1016]: at readableAddChunk (internal/streams/readable.js:284:9) Sep 29 11:19:58 garage volumio[1016]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 29 11:19:58 garage sudo[1287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-29 11:18 Sep 29 11:19:58 garage sudo[1287]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"