-- Logs begin at Thu 2019-02-14 12:12:00 EET, end at Thu 2024-02-22 13:59:56 EET. -- Feb 22 13:59:10 musicserver kernel: bcm2835-rng 3f104000.rng: hwrng registered Feb 22 13:59:10 musicserver kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Feb 22 13:59:10 musicserver kernel: brd: module loaded Feb 22 13:59:10 musicserver kernel: loop: module loaded Feb 22 13:59:10 musicserver kernel: Loading iSCSI transport class v2.0-870. Feb 22 13:59:10 musicserver kernel: usbcore: registered new interface driver lan78xx Feb 22 13:59:10 musicserver kernel: usbcore: registered new interface driver smsc95xx Feb 22 13:59:10 musicserver kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Feb 22 13:59:10 musicserver kernel: Core Release: 2.80a Feb 22 13:59:10 musicserver kernel: Setting default values for core params Feb 22 13:59:10 musicserver kernel: Finished setting default values for core params Feb 22 13:59:10 musicserver kernel: Using Buffer DMA mode Feb 22 13:59:10 musicserver kernel: Periodic Transfer Interrupt Enhancement - disabled Feb 22 13:59:10 musicserver kernel: Multiprocessor Interrupt Enhancement - disabled Feb 22 13:59:10 musicserver kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Feb 22 13:59:10 musicserver kernel: Dedicated Tx FIFOs mode Feb 22 13:59:10 musicserver kernel: Feb 22 13:59:10 musicserver kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = b7514000 dma = 0xf7514000 len=9024 Feb 22 13:59:10 musicserver kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Feb 22 13:59:10 musicserver kernel: dwc_otg: Microframe scheduler enabled Feb 22 13:59:10 musicserver kernel: Feb 22 13:59:10 musicserver kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Feb 22 13:59:10 musicserver kernel: Feb 22 13:59:10 musicserver kernel: WARN::hcd_init_fiq:458: FIQ ASM at 807cb80c length 36 Feb 22 13:59:10 musicserver kernel: Feb 22 13:59:10 musicserver kernel: WARN::hcd_init_fiq:497: MPHI regs_base at bb810000 Feb 22 13:59:10 musicserver kernel: dwc_otg 3f980000.usb: DWC OTG Controller Feb 22 13:59:10 musicserver kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Feb 22 13:59:10 musicserver kernel: dwc_otg 3f980000.usb: irq 89, io mem 0x00000000 Feb 22 13:59:10 musicserver kernel: Init: Port Power? op_state=1 Feb 22 13:59:10 musicserver kernel: Init: Power Port (0) Feb 22 13:59:10 musicserver kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Feb 22 13:59:10 musicserver kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 22 13:59:10 musicserver kernel: usb usb1: Product: DWC OTG Controller Feb 22 13:59:10 musicserver kernel: usb usb1: Manufacturer: Linux 6.1.69-v7+ dwc_otg_hcd Feb 22 13:59:10 musicserver kernel: usb usb1: SerialNumber: 3f980000.usb Feb 22 13:59:10 musicserver kernel: hub 1-0:1.0: USB hub found Feb 22 13:59:10 musicserver kernel: hub 1-0:1.0: 1 port detected Feb 22 13:59:10 musicserver kernel: dwc_otg: FIQ enabled Feb 22 13:59:10 musicserver kernel: dwc_otg: NAK holdoff enabled Feb 22 13:59:10 musicserver kernel: dwc_otg: FIQ split-transaction FSM enabled Feb 22 13:59:10 musicserver kernel: Module dwc_common_port init Feb 22 13:59:10 musicserver kernel: usbcore: registered new interface driver usb-storage Feb 22 13:59:10 musicserver kernel: mousedev: PS/2 mouse device common for all mice Feb 22 13:59:10 musicserver kernel: sdhci: Secure Digital Host Controller Interface driver Feb 22 13:59:10 musicserver kernel: sdhci: Copyright(c) Pierre Ossman Feb 22 13:59:10 musicserver kernel: sdhci-pltfm: SDHCI platform and OF driver helper Feb 22 13:59:10 musicserver kernel: ledtrig-cpu: registered to indicate activity on CPUs Feb 22 13:59:10 musicserver kernel: hid: raw HID events driver (C) Jiri Kosina Feb 22 13:59:10 musicserver kernel: usbcore: registered new interface driver usbhid Feb 22 13:59:10 musicserver kernel: usbhid: USB HID core driver Feb 22 13:59:10 musicserver kernel: Initializing XFRM netlink socket Feb 22 13:59:10 musicserver kernel: NET: Registered PF_PACKET protocol family Feb 22 13:59:10 musicserver kernel: Key type dns_resolver registered Feb 22 13:59:10 musicserver kernel: Registering SWP/SWPB emulation handler Feb 22 13:59:10 musicserver kernel: registered taskstats version 1 Feb 22 13:59:10 musicserver kernel: Loading compiled-in X.509 certificates Feb 22 13:59:10 musicserver kernel: Key type .fscrypt registered Feb 22 13:59:10 musicserver kernel: Key type fscrypt-provisioning registered Feb 22 13:59:10 musicserver kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Feb 22 13:59:10 musicserver kernel: 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2 Feb 22 13:59:10 musicserver kernel: printk: console [ttyAMA0] enabled Feb 22 13:59:10 musicserver kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Feb 22 13:59:10 musicserver kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Feb 22 13:59:10 musicserver kernel: sdhost: log_buf @ a9a62438 (f7513000) Feb 22 13:59:10 musicserver kernel: Freeing initrd memory: 13628K Feb 22 13:59:10 musicserver kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Feb 22 13:59:10 musicserver kernel: of_cfs_init Feb 22 13:59:10 musicserver kernel: of_cfs_init: OK Feb 22 13:59:10 musicserver kernel: Freeing unused kernel image (initmem) memory: 1024K Feb 22 13:59:10 musicserver kernel: Indeed it is in host mode hprt0 = 00021501 Feb 22 13:59:10 musicserver kernel: Run /init as init process Feb 22 13:59:10 musicserver kernel: with arguments: Feb 22 13:59:10 musicserver kernel: /init Feb 22 13:59:10 musicserver kernel: splash Feb 22 13:59:10 musicserver kernel: with environment: Feb 22 13:59:10 musicserver kernel: HOME=/ Feb 22 13:59:10 musicserver kernel: TERM=linux Feb 22 13:59:10 musicserver kernel: imgpart=/dev/mmcblk0p2 Feb 22 13:59:10 musicserver kernel: imgfile=/volumio_current.sqsh Feb 22 13:59:10 musicserver kernel: bootdelay=5 Feb 22 13:59:10 musicserver kernel: mmc0: host does not support reading read-only switch, assuming write-enable Feb 22 13:59:10 musicserver kernel: mmc0: new high speed SDHC card at address aaaa Feb 22 13:59:10 musicserver kernel: mmcblk0: mmc0:aaaa SU32G 29.7 GiB Feb 22 13:59:10 musicserver kernel: mmcblk0: p1 p2 p3 Feb 22 13:59:10 musicserver kernel: mmcblk0: mmc0:aaaa SU32G 29.7 GiB (quirks 0x00004000) Feb 22 13:59:10 musicserver kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Feb 22 13:59:10 musicserver kernel: Indeed it is in host mode hprt0 = 00001101 Feb 22 13:59:10 musicserver initramfs: Booting Volumio for BCM2835 Feb 22 13:59:10 musicserver initramfs: This script mounts rootfs RO with an overlay RW layer. Feb 22 13:59:10 musicserver kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Feb 22 13:59:10 musicserver kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 Feb 22 13:59:10 musicserver kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Feb 22 13:59:10 musicserver kernel: hub 1-1:1.0: USB hub found Feb 22 13:59:10 musicserver kernel: hub 1-1:1.0: 5 ports detected Feb 22 13:59:10 musicserver initramfs: IMGPART=/dev/mmcblk0p2 Feb 22 13:59:10 musicserver initramfs: IMGFILE=/volumio_current.sqsh Feb 22 13:59:10 musicserver initramfs: Boot delay (except first time) will be 5 seconds Feb 22 13:59:10 musicserver initramfs: /dev/mmcblk0p2: Feb 22 13:59:10 musicserver kernel: EXT4-fs (mmcblk0p2): recovery complete Feb 22 13:59:10 musicserver kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Feb 22 13:59:10 musicserver initramfs: Doing a 5 second delay here to give kernel load a headstart Feb 22 13:59:10 musicserver kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Feb 22 13:59:10 musicserver kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Feb 22 13:59:10 musicserver kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Feb 22 13:59:10 musicserver kernel: smsc95xx v2.0.0 Feb 22 13:59:10 musicserver kernel: SMSC LAN8700 usb-001:003:01: attached PHY driver (mii_bus:phy_addr=usb-001:003:01, irq=199) Feb 22 13:59:10 musicserver kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:db:77:4e Feb 22 13:59:10 musicserver initramfs: Checking for USB updates Feb 22 13:59:10 musicserver initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Feb 22 13:59:10 musicserver kernel: loop0: detected capacity change from 0 to 1004000 Feb 22 13:59:10 musicserver kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Feb 22 13:59:10 musicserver kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Feb 22 13:59:10 musicserver kernel: EXT4-fs (mmcblk0p3): recovery complete Feb 22 13:59:10 musicserver kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Feb 22 13:59:10 musicserver initramfs: With Option: Feb 22 13:59:10 musicserver initramfs: VOLUMIO_VERSION="3.616" Feb 22 13:59:10 musicserver initramfs: Finish initramfs, continue booting Volumio Feb 22 13:59:10 musicserver systemd[1]: System time before build time, advancing clock. Feb 22 13:59:10 musicserver kernel: NET: Registered PF_INET6 protocol family Feb 22 13:59:10 musicserver kernel: Segment Routing with IPv6 Feb 22 13:59:10 musicserver kernel: In-situ OAM (IOAM) with IPv6 Feb 22 13:59:10 musicserver 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) Feb 22 13:59:10 musicserver systemd[1]: Detected architecture arm. Feb 22 13:59:10 musicserver systemd[1]: Set hostname to . Feb 22 13:59:10 musicserver kernel: uart-pl011 3f201000.serial: no DMA platform data Feb 22 13:59:10 musicserver 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. Feb 22 13:59:10 musicserver systemd[1]: Listening on RPCbind Server Activation Socket. Feb 22 13:59:10 musicserver systemd[1]: Created slice User and Session Slice. Feb 22 13:59:10 musicserver systemd[1]: Listening on Journal Socket. Feb 22 13:59:10 musicserver systemd[1]: Starting Create list of required static device nodes for the current kernel... Feb 22 13:59:10 musicserver systemd[1]: Listening on udev Kernel Socket. Feb 22 13:59:10 musicserver systemd[1]: Listening on Journal Audit Socket. Feb 22 13:59:10 musicserver kernel: i2c_dev: i2c /dev entries driver Feb 22 13:59:10 musicserver systemd-journald[203]: Journal started Feb 22 13:59:10 musicserver systemd-journald[203]: Runtime journal (/run/log/journal/9522fdb065c2fbf4e8ff0b3a65b90e23) is 7.5M, max 30.0M, 22.5M free. Feb 22 13:59:10 musicserver systemd-modules-load[195]: Inserted module 'i2c_dev' Feb 22 13:59:10 musicserver fake-hwclock[196]: Thu Feb 22 11:59:10 UTC 2024 Feb 22 13:59:10 musicserver systemd[1]: Started Load/Save Random Seed. Feb 22 13:59:10 musicserver systemd[1]: Mounted Kernel Configuration File System. Feb 22 13:59:10 musicserver systemd[1]: dynamicswap.service: Succeeded. Feb 22 13:59:10 musicserver systemd[1]: Started Apply Kernel Variables. Feb 22 13:59:10 musicserver systemd[1]: Started Create System Users. Feb 22 13:59:10 musicserver systemd[1]: Starting Create Static Device Nodes in /dev... Feb 22 13:59:10 musicserver systemd[1]: Started udev Coldplug all Devices. Feb 22 13:59:10 musicserver systemd[1]: Starting Helper to synchronize boot up for ifupdown... Feb 22 13:59:10 musicserver systemd[1]: Started Create Static Device Nodes in /dev. Feb 22 13:59:10 musicserver systemd[1]: Reached target Local File Systems (Pre). Feb 22 13:59:10 musicserver systemd[1]: Mounting /var/spool/cups... Feb 22 13:59:10 musicserver systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Feb 22 13:59:10 musicserver systemd[1]: Mounting /tmp... Feb 22 13:59:10 musicserver systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Feb 22 13:59:10 musicserver systemd[1]: Mounting /var/log... Feb 22 13:59:10 musicserver systemd[1]: Starting udev Kernel Device Manager... Feb 22 13:59:10 musicserver systemd[1]: Started Helper to synchronize boot up for ifupdown. Feb 22 13:59:10 musicserver systemd[1]: Mounted /var/spool/cups. Feb 22 13:59:10 musicserver systemd[1]: Mounted /tmp. Feb 22 13:59:10 musicserver systemd[1]: Mounted /var/log. Feb 22 13:59:10 musicserver systemd[1]: Starting Flush Journal to Persistent Storage... Feb 22 13:59:10 musicserver systemd[1]: Mounting /var/spool/cups/tmp... Feb 22 13:59:10 musicserver systemd[1]: Mounted /var/spool/cups/tmp. Feb 22 13:59:10 musicserver systemd-udevd[241]: Network interface NamePolicy= disabled on kernel command line, ignoring. Feb 22 13:59:10 musicserver systemd-journald[203]: Runtime journal (/run/log/journal/9522fdb065c2fbf4e8ff0b3a65b90e23) is 7.5M, max 30.0M, 22.5M free. Feb 22 13:59:10 musicserver systemd[1]: Started udev Kernel Device Manager. Feb 22 13:59:10 musicserver systemd[1]: Started Flush Journal to Persistent Storage. Feb 22 13:59:10 musicserver systemd[1]: Starting Show Plymouth Boot Screen... Feb 22 13:59:10 musicserver systemd[1]: Received SIGRTMIN+20 from PID 255 (plymouthd). Feb 22 13:59:11 musicserver systemd[1]: Started Show Plymouth Boot Screen. Feb 22 13:59:11 musicserver systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Feb 22 13:59:11 musicserver systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Feb 22 13:59:11 musicserver systemd[1]: Reached target Local Encrypted Volumes. Feb 22 13:59:11 musicserver systemd[1]: Reached target Paths. Feb 22 13:59:11 musicserver kernel: mc: Linux media interface: v0.10 Feb 22 13:59:11 musicserver kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Feb 22 13:59:11 musicserver kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Feb 22 13:59:11 musicserver kernel: [vc_sm_connected_init]: start Feb 22 13:59:11 musicserver kernel: [vc_sm_connected_init]: installed successfully Feb 22 13:59:11 musicserver kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Feb 22 13:59:11 musicserver kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Feb 22 13:59:11 musicserver kernel: videodev: Linux video capture interface: v2.00 Feb 22 13:59:11 musicserver systemd[1]: Found device /dev/ttyAMA0. Feb 22 13:59:11 musicserver kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Feb 22 13:59:11 musicserver kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Feb 22 13:59:11 musicserver kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Feb 22 13:59:11 musicserver kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Feb 22 13:59:11 musicserver kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Feb 22 13:59:11 musicserver kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Feb 22 13:59:12 musicserver kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Feb 22 13:59:12 musicserver kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Feb 22 13:59:12 musicserver systemd-udevd[253]: Using default interface naming scheme 'v240'. Feb 22 13:59:12 musicserver kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Feb 22 13:59:12 musicserver kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Feb 22 13:59:12 musicserver systemd-udevd[253]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Feb 22 13:59:12 musicserver systemd[1]: Found device /dev/mmcblk0p1. Feb 22 13:59:12 musicserver systemd-udevd[250]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Feb 22 13:59:13 musicserver kernel: wm8804 1-003b: revision E Feb 22 13:59:14 musicserver systemd[1]: Condition check resulted in SMSC9512/9514 Fast Ethernet Adapter being skipped. Feb 22 13:59:14 musicserver systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Feb 22 13:59:14 musicserver systemd[1]: Condition check resulted in Huge Pages File System being skipped. Feb 22 13:59:14 musicserver systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Feb 22 13:59:14 musicserver systemd[1]: Condition check resulted in FUSE Control File System being skipped. Feb 22 13:59:14 musicserver systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Feb 22 13:59:14 musicserver systemd[1]: Starting File System Check on /dev/mmcblk0p1... Feb 22 13:59:14 musicserver systemd[1]: Started File System Check Daemon to report status. Feb 22 13:59:15 musicserver systemd-fsck[344]: fsck.fat 4.1 (2017-01-24) Feb 22 13:59:15 musicserver systemd-fsck[344]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Feb 22 13:59:15 musicserver systemd-fsck[344]: Automatically removing dirty bit. Feb 22 13:59:15 musicserver systemd-fsck[344]: Performing changes. Feb 22 13:59:15 musicserver systemd-fsck[344]: /dev/mmcblk0p1: 367 files, 33349/46774 clusters Feb 22 13:59:15 musicserver systemd[1]: Started File System Check on /dev/mmcblk0p1. Feb 22 13:59:15 musicserver systemd[1]: Mounting /boot... Feb 22 13:59:15 musicserver systemd[1]: Mounted /boot. Feb 22 13:59:15 musicserver systemd[1]: Reached target Local File Systems. Feb 22 13:59:15 musicserver systemd[1]: Starting Create Volatile Files and Directories... Feb 22 13:59:15 musicserver systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Feb 22 13:59:15 musicserver systemd[1]: Started ifup for eth0. Feb 22 13:59:15 musicserver systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Feb 22 13:59:15 musicserver systemd[1]: Starting Raise network interfaces... Feb 22 13:59:15 musicserver systemd[1]: Starting Preprocess NFS configuration... Feb 22 13:59:15 musicserver systemd[1]: plymouth-read-write.service: Succeeded. Feb 22 13:59:15 musicserver systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Feb 22 13:59:15 musicserver systemd[1]: Received SIGRTMIN+20 from PID 255 (plymouthd). Feb 22 13:59:15 musicserver systemd[1]: nfs-config.service: Succeeded. Feb 22 13:59:15 musicserver systemd[1]: Started Preprocess NFS configuration. Feb 22 13:59:15 musicserver systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Feb 22 13:59:15 musicserver systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Feb 22 13:59:15 musicserver systemd[1]: Reached target NFS client services. Feb 22 13:59:15 musicserver systemd[1]: Started Create Volatile Files and Directories. Feb 22 13:59:15 musicserver systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Feb 22 13:59:15 musicserver systemd[1]: Starting Update UTMP about System Boot/Shutdown... Feb 22 13:59:15 musicserver systemd[1]: Starting RPC bind portmap service... Feb 22 13:59:15 musicserver systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Feb 22 13:59:15 musicserver systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Feb 22 13:59:15 musicserver systemd[1]: Started Update UTMP about System Boot/Shutdown. Feb 22 13:59:15 musicserver systemd[1]: Reached target System Initialization. Feb 22 13:59:15 musicserver systemd[1]: apt-daily.timer: Not using persistent file timestamp Mon 2024-04-22 09:24:28 EEST as it is in the future. Feb 22 13:59:15 musicserver systemd[1]: Started Daily apt download activities. Feb 22 13:59:15 musicserver systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Feb 22 13:59:15 musicserver systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Mon 2024-04-22 06:29:18 EEST as it is in the future. Feb 22 13:59:15 musicserver systemd[1]: Started Daily apt upgrade and clean activities. Feb 22 13:59:15 musicserver systemd[1]: Listening on D-Bus System Message Bus Socket. Feb 22 13:59:15 musicserver systemd[1]: Listening on triggerhappy.socket. Feb 22 13:59:15 musicserver systemd[1]: Reached target Sockets. Feb 22 13:59:15 musicserver kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Feb 22 13:59:15 musicserver systemd[1]: Started Volumio Splash. Feb 22 13:59:15 musicserver systemd[1]: Reached target Basic System. Feb 22 13:59:15 musicserver systemd[1]: Started Volumio Log Rotation Service. Feb 22 13:59:15 musicserver systemd[1]: Starting triggerhappy global hotkey daemon... Feb 22 13:59:15 musicserver systemd[376]: volumiosplash.service: Failed to execute command: No such file or directory Feb 22 13:59:15 musicserver systemd[376]: volumiosplash.service: Failed at step EXEC spawning /bin/volumiosplash.sh: No such file or directory Feb 22 13:59:15 musicserver systemd[1]: Started volumio-remote-updater.service. Feb 22 13:59:15 musicserver systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Feb 22 13:59:15 musicserver systemd[1]: Starting dhcpcd on all interfaces... Feb 22 13:59:15 musicserver systemd[1]: Condition check resulted in Configure Bluetooth Modems connected by UART being skipped. Feb 22 13:59:15 musicserver systemd[1]: Started UPnP Renderer front-end to MPD. Feb 22 13:59:16 musicserver systemd[1]: Started Daily Cleanup of Temporary Directories. Feb 22 13:59:16 musicserver thd[382]: Unable to parse trigger line: Feb 22 13:59:16 musicserver thd[382]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Feb 22 13:59:16 musicserver thd[382]: Unable to parse trigger line: Feb 22 13:59:16 musicserver thd[382]: Found socket passed from systemd Feb 22 13:59:16 musicserver systemd[1]: Reached target Timers. Feb 22 13:59:16 musicserver systemd[1]: Starting Wireless Services... Feb 22 13:59:16 musicserver systemd[1]: Started Volumio Iptables Module. Feb 22 13:59:16 musicserver systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Feb 22 13:59:16 musicserver dhcpcd[385]: Not running dhcpcd because /etc/network/interfaces Feb 22 13:59:16 musicserver dhcpcd[385]: defines some interfaces that will use a Feb 22 13:59:16 musicserver dhcpcd[385]: DHCP client or static address Feb 22 13:59:16 musicserver systemd[1]: Starting Login Service... Feb 22 13:59:16 musicserver systemd[1]: Started D-Bus System Message Bus. Feb 22 13:59:16 musicserver kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Feb 22 13:59:16 musicserver kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Feb 22 13:59:16 musicserver kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Feb 22 13:59:16 musicserver systemd[1]: Starting WPA supplicant... Feb 22 13:59:16 musicserver systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Feb 22 13:59:16 musicserver sh[352]: command failed: No such device (-19) Feb 22 13:59:16 musicserver systemd[1]: Started Manage Sound Card State (restore and store). Feb 22 13:59:16 musicserver systemd[1]: Starting Save/Restore Sound Card State... Feb 22 13:59:16 musicserver systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Feb 22 13:59:16 musicserver alsactl[407]: alsactl 1.1.8 daemon started Feb 22 13:59:16 musicserver ifup[353]: command failed: No such device (-19) Feb 22 13:59:16 musicserver systemd[1]: Started RPC bind portmap service. Feb 22 13:59:16 musicserver systemd[1]: Started triggerhappy global hotkey daemon. Feb 22 13:59:16 musicserver systemd[1]: volumiosplash.service: Main process exited, code=exited, status=203/EXEC Feb 22 13:59:16 musicserver systemd[1]: volumiosplash.service: Failed with result 'exit-code'. Feb 22 13:59:16 musicserver systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Feb 22 13:59:16 musicserver systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Feb 22 13:59:16 musicserver systemd[1]: Failed to start dhcpcd on all interfaces. Feb 22 13:59:16 musicserver systemd[1]: Reached target Remote File Systems (Pre). Feb 22 13:59:16 musicserver systemd[1]: Reached target Remote File Systems. Feb 22 13:59:16 musicserver systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Feb 22 13:59:16 musicserver systemd[1]: Reached target RPC Port Mapper. Feb 22 13:59:16 musicserver systemd-logind[393]: New seat seat0. Feb 22 13:59:16 musicserver avahi-daemon[405]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Feb 22 13:59:16 musicserver avahi-daemon[405]: Successfully dropped root privileges. Feb 22 13:59:16 musicserver avahi-daemon[405]: avahi-daemon 0.7 starting up. Feb 22 13:59:17 musicserver ifup[353]: command failed: No such device (-19) Feb 22 13:59:17 musicserver kernel: 8021q: 802.1Q VLAN Support v1.8 Feb 22 13:59:17 musicserver systemd[1]: Started Login Service. Feb 22 13:59:17 musicserver systemd[1]: Started Save/Restore Sound Card State. Feb 22 13:59:17 musicserver avahi-daemon[405]: Successfully called chroot(). Feb 22 13:59:17 musicserver avahi-daemon[405]: Successfully dropped remaining capabilities. Feb 22 13:59:17 musicserver avahi-daemon[405]: Loading service file /services/volumio.service. Feb 22 13:59:17 musicserver wpa_supplicant[400]: Successfully initialized wpa_supplicant Feb 22 13:59:17 musicserver avahi-daemon[405]: Network interface enumeration completed. Feb 22 13:59:17 musicserver avahi-daemon[405]: Server startup complete. Host name is musicserver.local. Local service cookie is 2746504822. Feb 22 13:59:17 musicserver avahi-daemon[405]: Service "musicserver" (/services/volumio.service) successfully established. Feb 22 13:59:18 musicserver systemd[1]: Started Avahi mDNS/DNS-SD Stack. Feb 22 13:59:18 musicserver systemd[1]: Started WPA supplicant. Feb 22 13:59:18 musicserver systemd[1]: Reached target Sound Card. Feb 22 13:59:18 musicserver sh[352]: eth0: waiting for carrier Feb 22 13:59:18 musicserver dhcpcd[431]: eth0: waiting for carrier Feb 22 13:59:18 musicserver kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Feb 22 13:59:18 musicserver kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Feb 22 13:59:18 musicserver sh[352]: eth0: carrier acquired Feb 22 13:59:18 musicserver dhcpcd[431]: eth0: carrier acquired Feb 22 13:59:18 musicserver volumio-remote-updater[384]: Error: No active session Feb 22 13:59:18 musicserver sh[352]: DUID 00:01:00:01:2d:4b:cc:6b:b8:27:eb:db:77:4e Feb 22 13:59:18 musicserver sh[352]: eth0: IAID eb:db:77:4e Feb 22 13:59:18 musicserver sh[352]: eth0: adding address fe80::d28b:978c:9691:3f98 Feb 22 13:59:18 musicserver sh[352]: ipv6_addaddr1: Permission denied Feb 22 13:59:18 musicserver dhcpcd[431]: DUID 00:01:00:01:2d:4b:cc:6b:b8:27:eb:db:77:4e Feb 22 13:59:18 musicserver dhcpcd[431]: eth0: IAID eb:db:77:4e Feb 22 13:59:18 musicserver dhcpcd[431]: eth0: adding address fe80::d28b:978c:9691:3f98 Feb 22 13:59:18 musicserver dhcpcd[431]: ipv6_addaddr1: Permission denied Feb 22 13:59:18 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:18] [info] asio async_connect error: system:111 (Connection refused) Feb 22 13:59:18 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:18] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 22 13:59:18 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:18] [error] handle_connect error: Underlying Transport Error Feb 22 13:59:18 musicserver systemd[1]: Started Raise network interfaces. Feb 22 13:59:18 musicserver systemd[1]: Reached target Network. Feb 22 13:59:18 musicserver volumio[386]: Could not open config: /tmp/upmpdcli.conf Feb 22 13:59:18 musicserver systemd[1]: Starting Permit User Sessions... Feb 22 13:59:18 musicserver systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Feb 22 13:59:18 musicserver systemd[1]: Reached target Network is Online. Feb 22 13:59:18 musicserver systemd[1]: Starting LSB: Brings up/down network automatically... Feb 22 13:59:18 musicserver systemd[1]: Starting /etc/rc.local Compatibility... Feb 22 13:59:18 musicserver systemd[1]: Starting Network Time Service... Feb 22 13:59:18 musicserver loadcpufreq[424]: Loading cpufreq kernel modules...done (none). Feb 22 13:59:18 musicserver systemd[1]: Starting Samba NMB Daemon... Feb 22 13:59:18 musicserver sh[352]: eth0: soliciting an IPv6 router Feb 22 13:59:18 musicserver dhcpcd[431]: eth0: soliciting an IPv6 router Feb 22 13:59:18 musicserver systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 22 13:59:19 musicserver systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 13:59:19 musicserver systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 13:59:19 musicserver sh[352]: eth0: rebinding lease of 192.168.1.204 Feb 22 13:59:19 musicserver dhcpcd[431]: eth0: rebinding lease of 192.168.1.204 Feb 22 13:59:19 musicserver systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Feb 22 13:59:19 musicserver systemd[1]: Started Permit User Sessions. Feb 22 13:59:19 musicserver systemd[1]: Started /etc/rc.local Compatibility. Feb 22 13:59:19 musicserver systemd[1]: iptables.service: Succeeded. Feb 22 13:59:19 musicserver systemd[1]: Starting Terminate Plymouth Boot Screen... Feb 22 13:59:19 musicserver systemd[1]: Starting Hold until boot process finishes up... Feb 22 13:59:19 musicserver systemd[1]: Starting LSB: set CPUFreq kernel parameters... Feb 22 13:59:19 musicserver sh[352]: eth0: probing address 192.168.1.204/24 Feb 22 13:59:19 musicserver dhcpcd[431]: eth0: probing address 192.168.1.204/24 Feb 22 13:59:19 musicserver systemd[1]: Received SIGRTMIN+21 from PID 255 (plymouthd). Feb 22 13:59:19 musicserver ifplugd[525]: Network Interface Plugging Daemon...error: unexpectedly disconnected from boot status daemon Feb 22 13:59:19 musicserver systemd[1]: plymouth-start.service: Succeeded. Feb 22 13:59:19 musicserver haveged[372]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Feb 22 13:59:19 musicserver haveged[372]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Feb 22 13:59:19 musicserver haveged[372]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.002 Feb 22 13:59:19 musicserver haveged[372]: haveged: fills: 0, generated: 0 Feb 22 13:59:19 musicserver systemd[1]: plymouth-quit.service: Succeeded. Feb 22 13:59:19 musicserver systemd[1]: Started Terminate Plymouth Boot Screen. Feb 22 13:59:19 musicserver systemd[1]: plymouth-quit-wait.service: Succeeded. Feb 22 13:59:19 musicserver systemd[1]: Started Hold until boot process finishes up. Feb 22 13:59:19 musicserver systemd[1]: Received SIGRTMIN+21 from PID 255 (n/a). Feb 22 13:59:19 musicserver ifplugd(eth0)[573]: ifplugd 0.28 initializing. Feb 22 13:59:19 musicserver ifplugd(eth0)[573]: Using interface eth0/B8:27:EB:DB:77:4E with driver (version: 6.1.69-v7+) Feb 22 13:59:19 musicserver systemd[1]: Started Serial Getty on ttyAMA0. Feb 22 13:59:19 musicserver ifplugd(eth0)[573]: Using detection mode: SIOCETHTOOL Feb 22 13:59:19 musicserver ifplugd(eth0)[573]: Initialization complete, link beat detected. Feb 22 13:59:19 musicserver ntpd[532]: ntpd 4.2.8p12@1.3728-o (1): Starting Feb 22 13:59:19 musicserver ntpd[532]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Feb 22 13:59:19 musicserver systemd[1]: Started Getty on tty1. Feb 22 13:59:19 musicserver systemd[1]: Reached target Login Prompts. Feb 22 13:59:19 musicserver systemd[1]: Started Network Time Service. Feb 22 13:59:19 musicserver ntpd[576]: proto: precision = 1.771 usec (-19) Feb 22 13:59:19 musicserver ifplugd(eth0)[573]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Feb 22 13:59:19 musicserver ntpd[576]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Feb 22 13:59:19 musicserver ntpd[576]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Feb 22 13:59:19 musicserver ntpd[576]: Listen and drop on 0 v6wildcard [::]:123 Feb 22 13:59:19 musicserver ntpd[576]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Feb 22 13:59:19 musicserver ntpd[576]: Listen normally on 2 lo 127.0.0.1:123 Feb 22 13:59:19 musicserver ntpd[576]: Listening on routing socket on fd #19 for interface updates Feb 22 13:59:19 musicserver ntpd[576]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 22 13:59:19 musicserver ntpd[576]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 22 13:59:19 musicserver ifplugd(eth0)[573]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Feb 22 13:59:19 musicserver cpufrequtils[555]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Feb 22 13:59:19 musicserver systemd[1]: Started LSB: set CPUFreq kernel parameters. Feb 22 13:59:20 musicserver ntpd[576]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Feb 22 13:59:20 musicserver nmbd[544]: [2024/02/22 13:59:20.823777, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Feb 22 13:59:20 musicserver nmbd[544]: started asyncdns process 594 Feb 22 13:59:20 musicserver nmbd[544]: [2024/02/22 13:59:20.831828, 0] ../lib/util/become_daemon.c:149(daemon_status) Feb 22 13:59:20 musicserver nmbd[544]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Feb 22 13:59:20 musicserver nmbd[544]: [2024/02/22 13:59:20.833377, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Feb 22 13:59:20 musicserver nmbd[544]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Feb 22 13:59:21 musicserver wireless.js[389]: WIRELESS: No wireless interface, exiting Feb 22 13:59:21 musicserver ntpd[576]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Feb 22 13:59:21 musicserver iw[599]: command failed: No such device (-19) Feb 22 13:59:21 musicserver iwconfig[602]: Error for wireless request "Set Power Management" (8B2C) : Feb 22 13:59:21 musicserver iwconfig[602]: SET failed on device wlan0 ; No such device. Feb 22 13:59:21 musicserver systemd[1]: wireless.service: Succeeded. Feb 22 13:59:21 musicserver systemd[1]: Started Wireless Services. Feb 22 13:59:21 musicserver systemd[1]: Started Volumio Backend Module. Feb 22 13:59:21 musicserver systemd[1]: Started Volumio Cpu Tweaker. Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: Setting RT Priority for mpd Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: pid 35's current scheduling policy: SCHED_OTHER Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: pid 35's current scheduling priority: 0 Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: Setting MPD Affinity Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: pid 3's current affinity mask: 1 Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Feb 22 13:59:21 musicserver volumio-cpu-tweak[606]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Feb 22 13:59:21 musicserver systemd[1]: volumio_cpu_tweak.service: Succeeded. Feb 22 13:59:22 musicserver ntpd[576]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Feb 22 13:59:23 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:23] [info] asio async_connect error: system:111 (Connection refused) Feb 22 13:59:23 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:23] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 22 13:59:23 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:23] [error] handle_connect error: Underlying Transport Error Feb 22 13:59:23 musicserver ntpd[576]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Feb 22 13:59:25 musicserver sh[352]: eth0: leased 192.168.1.204 for 86400 seconds Feb 22 13:59:25 musicserver dhcpcd[431]: eth0: leased 192.168.1.204 for 86400 seconds Feb 22 13:59:25 musicserver dhcpcd[431]: eth0: adding route to 192.168.1.0/24 Feb 22 13:59:25 musicserver sh[352]: eth0: adding route to 192.168.1.0/24 Feb 22 13:59:25 musicserver sh[352]: eth0: adding default route via 192.168.1.1 Feb 22 13:59:25 musicserver dhcpcd[431]: eth0: adding default route via 192.168.1.1 Feb 22 13:59:25 musicserver avahi-daemon[405]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.204. Feb 22 13:59:25 musicserver avahi-daemon[405]: New relevant interface eth0.IPv4 for mDNS. Feb 22 13:59:25 musicserver avahi-daemon[405]: Registering new address record for 192.168.1.204 on eth0.IPv4. Feb 22 13:59:25 musicserver sh[352]: forked to background, child pid 643 Feb 22 13:59:25 musicserver dhcpcd[431]: forked to background, child pid 643 Feb 22 13:59:25 musicserver nmbd[544]: [2024/02/22 13:59:25.847002, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 22 13:59:25 musicserver nmbd[544]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 22 13:59:25 musicserver systemd[1]: Started Samba NMB Daemon. Feb 22 13:59:25 musicserver nmbd[544]: [2024/02/22 13:59:25.897102, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 22 13:59:25 musicserver nmbd[544]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.204 for name WORKGROUP<1d>. Feb 22 13:59:25 musicserver nmbd[544]: This response was from IP 192.168.1.7, reporting an IP address of 192.168.1.7. Feb 22 13:59:25 musicserver nmbd[544]: [2024/02/22 13:59:25.897966, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 22 13:59:25 musicserver nmbd[544]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.1.204 for name WORKGROUP<1d>. Feb 22 13:59:25 musicserver nmbd[544]: This response was from IP 192.168.1.7, reporting an IP address of 192.168.1.7. Feb 22 13:59:25 musicserver nmbd[544]: [2024/02/22 13:59:25.898594, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 22 13:59:25 musicserver nmbd[544]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.1.204 for name WORKGROUP<1d>. Feb 22 13:59:25 musicserver nmbd[544]: This response was from IP 192.168.1.7, reporting an IP address of 192.168.1.7. Feb 22 13:59:25 musicserver ifplugd(eth0)[573]: client: ifup: interface eth0 already configured Feb 22 13:59:25 musicserver sh[352]: eth0=eth0 Feb 22 13:59:25 musicserver systemd[1]: Starting Samba Winbind Daemon... Feb 22 13:59:26 musicserver ifplugd(eth0)[573]: Program executed successfully. Feb 22 13:59:26 musicserver ifplugd[525]: start eth0...done. Feb 22 13:59:26 musicserver systemd[1]: Started LSB: Brings up/down network automatically. Feb 22 13:59:26 musicserver winbindd[665]: [2024/02/22 13:59:26.511572, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 22 13:59:26 musicserver winbindd[665]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 22 13:59:26 musicserver winbindd[665]: [2024/02/22 13:59:26.543456, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 22 13:59:26 musicserver winbindd[665]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 22 13:59:26 musicserver systemd[1]: Started Samba Winbind Daemon. Feb 22 13:59:26 musicserver systemd[1]: Starting Samba SMB Daemon... Feb 22 13:59:26 musicserver ntpd[576]: Listen normally on 3 eth0 192.168.1.204:123 Feb 22 13:59:26 musicserver ntpd[576]: new interface(s) found: waking up resolver Feb 22 13:59:27 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:27 musicserver volumio[605]: info: ----- Volumio3 ---- Feb 22 13:59:27 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:27 musicserver volumio[605]: info: ----- System startup ---- Feb 22 13:59:27 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:27 musicserver winbindd[665]: [2024/02/22 13:59:27.440644, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Feb 22 13:59:27 musicserver winbindd[665]: res_names->count = 2, expected 3 Feb 22 13:59:27 musicserver smbd[682]: [2024/02/22 13:59:27.514737, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 22 13:59:27 musicserver smbd[682]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 22 13:59:27 musicserver systemd[1]: Started Samba SMB Daemon. Feb 22 13:59:27 musicserver systemd[1]: Reached target Multi-User System. Feb 22 13:59:27 musicserver systemd[1]: Reached target Graphical Interface. Feb 22 13:59:27 musicserver systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 22 13:59:27 musicserver systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 22 13:59:27 musicserver systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 22 13:59:27 musicserver systemd[1]: Startup finished in 10.782s (kernel) + 20.423s (userspace) = 31.206s. Feb 22 13:59:29 musicserver volumio[605]: info: MYVOLUMIO Environment detected Feb 22 13:59:29 musicserver volumio[605]: info: Plugin folders cleanup Feb 22 13:59:29 musicserver volumio[605]: info: Scanning into folder /volumio/app/plugins/ Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category audio_interface Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category miscellanea Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category music_service Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category plugins.json Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category system_controller Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category user_interface Feb 22 13:59:29 musicserver volumio[605]: info: Scanning into folder /data/plugins/ Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category music_service Feb 22 13:59:29 musicserver volumio[605]: info: Scanning category user_interface Feb 22 13:59:29 musicserver volumio[605]: info: Plugin folders cleanup completed Feb 22 13:59:29 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:29 musicserver volumio[605]: info: ----- Core plugins startup ---- Feb 22 13:59:29 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:29 musicserver volumio[605]: info: Loading plugins from folder /volumio/app/plugins/ Feb 22 13:59:29 musicserver volumio[605]: info: Adding plugin upnp to MyMusic Plugins Feb 22 13:59:29 musicserver volumio[605]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 22 13:59:29 musicserver volumio[605]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 22 13:59:29 musicserver volumio[605]: info: Loading plugins from folder /data/plugins/ Feb 22 13:59:29 musicserver volumio[605]: info: Loading plugin "system"... Feb 22 13:59:29 musicserver volumio[605]: info: Loading plugin "appearance"... Feb 22 13:59:31 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:31] [connect] Successful connection Feb 22 13:59:32 musicserver volumio[605]: info: Loading plugin "network"... Feb 22 13:59:32 musicserver volumio[605]: info: Refreshing Cached IP Addresses Feb 22 13:59:32 musicserver volumio[605]: info: Loading plugin "services"... Feb 22 13:59:32 musicserver volumio[605]: info: Loading plugin "alsa_controller"... Feb 22 13:59:32 musicserver sudo[698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 22 13:59:32 musicserver sudo[696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 22 13:59:32 musicserver sudo[694]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 22 13:59:32 musicserver sudo[698]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:32 musicserver sudo[694]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:32 musicserver sudo[696]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:32 musicserver sudo[694]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:32 musicserver sudo[698]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:32 musicserver sudo[696]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:32 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 13:59:32 musicserver volumio[605]: info: Loading plugin "wizard"... Feb 22 13:59:32 musicserver volumio[605]: info: Loading plugin "networkfs"... Feb 22 13:59:32 musicserver volumio[605]: info: Starting Udev Watcher for removable devices Feb 22 13:59:32 musicserver sudo[709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=gkalp,password=f565nun!,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.7/audio-files /mnt/NAS/audio-files Feb 22 13:59:32 musicserver sudo[709]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:33 musicserver volumio[605]: info: Ignoring mount for partition: boot Feb 22 13:59:33 musicserver volumio[605]: info: Ignoring mount for partition: volumio Feb 22 13:59:33 musicserver volumio[605]: info: Ignoring mount for partition: volumio_data Feb 22 13:59:33 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 22 13:59:33 musicserver volumio[605]: info: Loading plugin "volumio_command_line_client"... Feb 22 13:59:33 musicserver volumio[605]: info: Loading plugin "upnp"... Feb 22 13:59:33 musicserver volumio[605]: info: [1708603173064] Starting Upmpd Daemon Feb 22 13:59:33 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 22 13:59:33 musicserver volumio[605]: info: Loading plugin "my_music"... Feb 22 13:59:33 musicserver volumio[605]: info: Loading plugin "mpd"... Feb 22 13:59:33 musicserver kernel: Key type cifs.spnego registered Feb 22 13:59:33 musicserver kernel: Key type cifs.idmap registered Feb 22 13:59:33 musicserver 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. Feb 22 13:59:33 musicserver kernel: CIFS: Attempting to mount \\192.168.1.7\audio-files Feb 22 13:59:33 musicserver sudo[709]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:34 musicserver volumio[605]: info: Loading plugin "upnp_browser"... Feb 22 13:59:34 musicserver volumio[605]: info: Loading plugin "alarm-clock"... Feb 22 13:59:35 musicserver volumio[605]: info: Loading plugin "airplay_emulation"... Feb 22 13:59:35 musicserver volumio[605]: info: Starting Shairport Sync Feb 22 13:59:35 musicserver volumio[605]: info: Loading plugin "last_100"... Feb 22 13:59:35 musicserver volumio[605]: info: Loading plugin "webradio"... Feb 22 13:59:35 musicserver volumio[605]: info: Loading plugin "i2s_dacs"... Feb 22 13:59:35 musicserver volumio[605]: info: Loading plugin "volumiodiscovery"... Feb 22 13:59:35 musicserver volumio[605]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 22 13:59:35 musicserver volumio[605]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 22 13:59:35 musicserver node[605]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 22 13:59:35 musicserver volumio[605]: *** WARNING *** For more information see Feb 22 13:59:35 musicserver volumio[605]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 22 13:59:35 musicserver volumio[605]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 22 13:59:35 musicserver volumio[605]: *** WARNING *** For more information see Feb 22 13:59:35 musicserver node[605]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 22 13:59:35 musicserver node[605]: *** WARNING *** For more information see Feb 22 13:59:35 musicserver node[605]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 22 13:59:35 musicserver node[605]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 22 13:59:35 musicserver node[605]: *** WARNING *** For more information see Feb 22 13:59:35 musicserver volumio[605]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 22 13:59:35 musicserver volumio[605]: info: Discovery: Started advertising with name: musicserver Feb 22 13:59:35 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 22 13:59:35 musicserver volumio[605]: info: Loading plugin "spop"... Feb 22 13:59:38 musicserver volumio[605]: info: Loading plugin "outputs"... Feb 22 13:59:38 musicserver volumio[605]: info: Loading plugin "albumart"... Feb 22 13:59:38 musicserver volumio[605]: info: Plugin example_plugin is not enabled Feb 22 13:59:38 musicserver volumio[605]: info: Loading plugin "inputs"... Feb 22 13:59:39 musicserver volumio[605]: info: Loading plugin "updater_comm"... Feb 22 13:59:39 musicserver volumio[605]: info: Plugin mpdemulation is not enabled Feb 22 13:59:39 musicserver volumio[605]: info: Loading plugin "rest_api"... Feb 22 13:59:39 musicserver volumio[605]: info: Loading plugin "websocket"... Feb 22 13:59:39 musicserver volumio[605]: info: Loading plugin "Systeminfo"... Feb 22 13:59:39 musicserver volumio[605]: Forking 3 albumart workers Feb 22 13:59:40 musicserver volumio[605]: info: Loading i18n strings for locale en Feb 22 13:59:40 musicserver volumio[605]: Updating browse sources language Feb 22 13:59:40 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::initPlayerControls Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 13:59:41 musicserver volumio[605]: Express server listening on port 3000 Feb 22 13:59:41 musicserver volumio[605]: [Metrics] WebUI: 16s 146.39ms Feb 22 13:59:41 musicserver volumio[605]: info: CoreStateMachine::resetVolumioState Feb 22 13:59:41 musicserver volumio[605]: info: CoreStateMachine::getcurrentVolume Feb 22 13:59:41 musicserver volumio[605]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 13:59:41 musicserver volumio[605]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 22 13:59:41 musicserver volumio[605]: wlan0 Interface doesn't support scanning. Feb 22 13:59:41 musicserver volumio[605]: info: Cannot use regular scanning, forcing with ap-force Feb 22 13:59:41 musicserver sudo[774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 22 13:59:41 musicserver sudo[774]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:41 musicserver sudo[774]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:41 musicserver volumio[605]: command failed: No such device (-19) Feb 22 13:59:41 musicserver volumio[605]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 22 13:59:41 musicserver volumio[605]: command failed: No such device (-19) Feb 22 13:59:41 musicserver volumio[605]: Starting albumart workers Feb 22 13:59:41 musicserver volumio[605]: Starting albumart workers Feb 22 13:59:41 musicserver volumio[605]: Starting albumart workers Feb 22 13:59:42 musicserver volumio[605]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 13:59:42 musicserver volumio[605]: info: Reloading queue from file Feb 22 13:59:42 musicserver volumio[605]: info: CoreStateMachine::setRepeat null single undefined Feb 22 13:59:42 musicserver volumio[605]: info: CoreStateMachine::pushState Feb 22 13:59:42 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::volumioPushState Feb 22 13:59:42 musicserver volumio[605]: info: CoreStateMachine::setRandom null Feb 22 13:59:42 musicserver volumio[605]: info: CoreStateMachine::pushState Feb 22 13:59:42 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::volumioPushState Feb 22 13:59:42 musicserver volumio[605]: info: Setting Device type: Raspberry PI Feb 22 13:59:42 musicserver volumio[605]: info: Completed loading Core Plugins Feb 22 13:59:42 musicserver volumio[605]: info: Preparing to generate the ALSA configuration file Feb 22 13:59:42 musicserver volumio[605]: info: VolumeController:: Volume=undefined Mute =false Feb 22 13:59:42 musicserver volumio[605]: info: CoreStateMachine::pushState Feb 22 13:59:42 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::volumioPushState Feb 22 13:59:42 musicserver volumio[605]: info: CoreStateMachine::updateTrackBlock Feb 22 13:59:42 musicserver volumio[605]: info: CorePlayQueue::getTrackBlock Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 13:59:42 musicserver volumio[605]: info: Asound.conf file unchanged, so no further update is needed Feb 22 13:59:42 musicserver volumio[605]: info: Output device has changed, restarting MPD Feb 22 13:59:42 musicserver volumio[605]: info: Output device has changed, restarting Shairport Sync Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:42 musicserver sudo[786]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 13:59:42 musicserver sudo[786]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:42 musicserver sudo[786]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:42 musicserver sudo[788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 13:59:42 musicserver sudo[788]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:42 musicserver volumio[605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 13:59:42 musicserver volumio[605]: info: ___________ START PLUGINS ___________ Feb 22 13:59:42 musicserver volumio[605]: info: ControllerMpd::onStart: Initializing MPD Feb 22 13:59:42 musicserver volumio[605]: info: Creating MPD Configuration file Feb 22 13:59:42 musicserver systemd[1]: Listening on mpd.socket. Feb 22 13:59:42 musicserver systemd[1]: Starting Music Player Daemon... Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 13:59:42 musicserver volumio[605]: info: [1708603182929] CoreMusicLibrary::Adding element Media Servers Feb 22 13:59:42 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 13:59:43 musicserver sudo[797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 13:59:43 musicserver sudo[797]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:43 musicserver sudo[799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 13:59:43 musicserver sudo[799]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 13:59:43 musicserver sudo[797]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:43 musicserver systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 22 13:59:43 musicserver systemd[1]: mpd.service: Succeeded. Feb 22 13:59:43 musicserver systemd[1]: Stopped Music Player Daemon. Feb 22 13:59:43 musicserver systemd[1]: Starting Music Player Daemon... Feb 22 13:59:43 musicserver volumio[605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 13:59:43 musicserver volumio[605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 13:59:43 musicserver volumio[605]: info: [1708603183476] CoreMusicLibrary::Adding element Last_100 Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 13:59:43 musicserver sudo[805]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 13:59:43 musicserver volumio[605]: info: [1708603183496] CoreMusicLibrary::Adding element Webradio Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 13:59:43 musicserver sudo[805]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:43 musicserver sudo[805]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 13:59:43 musicserver sudo[805]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:43 musicserver volumio[605]: info: Creating Spotify config file Feb 22 13:59:43 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:43 musicserver volumio[605]: info: Volumio Calling Home Feb 22 13:59:44 musicserver sudo[839]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 22 13:59:44 musicserver volumio[605]: info: Discovery: adding ac160bc8-6e36-4366-993d-17284e02e61a Feb 22 13:59:44 musicserver sudo[839]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:44 musicserver volumio[605]: info: Discovery: Found device musicserver Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::volumioGetState Feb 22 13:59:44 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:44 musicserver sudo[839]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:44 musicserver sudo[841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 22 13:59:44 musicserver sudo[841]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:44 musicserver volumio[605]: info: MPD Permissions set Feb 22 13:59:44 musicserver volumio[605]: info: MPD Permissions set Feb 22 13:59:44 musicserver volumio[605]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Feb 22 13:59:44 musicserver sudo[841]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:44 musicserver volumio[605]: info: Volumio called home Feb 22 13:59:44 musicserver volumio[605]: info: Spotify config file written Feb 22 13:59:44 musicserver sudo[848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 13:59:44 musicserver sudo[848]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:44 musicserver volumio[605]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver systemd[1]: Started go-librespot Daemon. Feb 22 13:59:44 musicserver go-librespot[850]: Librespot-go daemon starting... Feb 22 13:59:44 musicserver sudo[848]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 13:59:44 musicserver volumio[605]: info: An error occurred while refreshing Spotify Token Error: certificate is not yet valid Feb 22 13:59:44 musicserver volumio[605]: info: VolumeController:: Volume=undefined Mute =false Feb 22 13:59:44 musicserver volumio[605]: info: CoreStateMachine::pushState Feb 22 13:59:44 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:44 musicserver volumio[605]: info: CoreCommandRouter::volumioPushState Feb 22 13:59:44 musicserver volumio[605]: info: Starting Shairport Sync Feb 22 13:59:44 musicserver volumio[605]: info: Starting Shairport Sync Feb 22 13:59:45 musicserver sudo[866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 13:59:45 musicserver sudo[866]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:45 musicserver volumio[605]: info: Starting Shairport Sync Feb 22 13:59:45 musicserver sudo[868]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 22 13:59:45 musicserver sudo[868]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:45 musicserver sudo[871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 13:59:45 musicserver sudo[871]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:45 musicserver systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 22 13:59:45 musicserver sudo[874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 13:59:45 musicserver sudo[874]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 13:59:45 musicserver systemd[1]: Started UPnP Renderer front-end to MPD. Feb 22 13:59:45 musicserver systemd[1]: systemd-fsckd.service: Succeeded. Feb 22 13:59:45 musicserver systemd[1]: shairport-sync.service: Succeeded. Feb 22 13:59:45 musicserver systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 22 13:59:45 musicserver go-librespot[850]: time="2024-02-22T13:59:45+02:00" level=info msg="generated new device id: f498c6ea27b593a0ebba99728f195b25cf2df380" Feb 22 13:59:45 musicserver go-librespot[850]: time="2024-02-22T13:59:45+02:00" level=debug msg="stored credentials found for 31jcagqiiauvtp3qjkdtxmjefuv4" Feb 22 13:59:45 musicserver sudo[868]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:45 musicserver volumio[605]: info: Upmpdcli Daemon Started Feb 22 13:59:45 musicserver volumio[605]: info: CoreCommandRouter::volumioGetState Feb 22 13:59:45 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:45 musicserver systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 22 13:59:45 musicserver sudo[866]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:45 musicserver sudo[871]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:45 musicserver sudo[874]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:45 musicserver volumio[605]: info: Shairport-Sync Started Feb 22 13:59:45 musicserver volumio[605]: Error adding Membership: Error: addMembership EINVAL Feb 22 13:59:45 musicserver volumio[605]: info: Shairport-Sync Started Feb 22 13:59:45 musicserver volumio[605]: info: Shairport-Sync Started Feb 22 13:59:46 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:46] [connect] Successful connection Feb 22 13:59:46 musicserver volumio-remote-updater[384]: [2024-02-22 13:59:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1708603186 101 Feb 22 13:59:46 musicserver volumio[605]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2 Feb 22 13:59:46 musicserver go-librespot[850]: time="2024-02-22T13:59:46+02:00" level=debug msg="obtained new client token: AAAz7KOT2majwO9ccIRCo2NBmILf8VRKsW1KZOtLnJdVzcitlpiCtHY5xWpUMoqPsra7WoLuF8fzHOkvwU+HRvdQzNSDoYuIl/koiUxuUx/zBlYC6ljHgiEZ//LV19X6ll3keAisTVOMk9tIcXrkIw9AsjcGaN1q3oxYU1hkYvnq8HJBPAHpbVvODN+G8P84TTeT9BVDVyVE1mP/Hu3VoOd0fXbwtN13dnCZam3mDA8vErGH5dZHGQ0/8rvGuw==" Feb 22 13:59:46 musicserver go-librespot[850]: time="2024-02-22T13:59:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 22 13:59:46 musicserver go-librespot[850]: time="2024-02-22T13:59:46+02:00" level=debug msg="completed keyexchange" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="completed challenge" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="authenticated as 31jcagqiiauvtp3qjkdtxmjefuv4" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="authenticated as 31jcagqiiauvtp3qjkdtxmjefuv4" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 22 13:59:47 musicserver mpd[822]: Feb 22 13:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 22 13:59:47 musicserver volumio[605]: info: go-librespot daemon successfully initialized Feb 22 13:59:47 musicserver systemd[1]: Started Music Player Daemon. Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="dealer connection opened" Feb 22 13:59:47 musicserver volumio[605]: Upnp client error: Error: This socket has been ended by the other party Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Feb 22 13:59:47 musicserver go-librespot[850]: time="2024-02-22T13:59:47+02:00" level=debug msg="received connection id: OTUwYzgxZjItNTY5ZC00NjBlLTk1OTQtYTc3ZmUwY2FjMWQxK2RlYWxlcit0Y3A6Ly9nZXcxLWRlYWxlci1hLXJ2emouZ2V3MS5zcG90aWZ5Lm5ldDo1NzAwKzgwMDVERkQyMzk5RTQ3QTc0OUJBMjQzNzMxNTJFRTAyNzY5MUVBOEQyMUQyRDc2QjE0QjlCMTcxOTYyQkM2MzY=" Feb 22 13:59:47 musicserver sudo[788]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:47 musicserver sudo[799]: pam_unix(sudo:session): session closed for user root Feb 22 13:59:48 musicserver volumio[605]: info: Completed starting Core Plugins Feb 22 13:59:48 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:48 musicserver volumio[605]: info: ----- MyVolumio plugins startup ---- Feb 22 13:59:48 musicserver volumio[605]: info: ------------------------------------------- Feb 22 13:59:48 musicserver volumio[605]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 22 13:59:48 musicserver volumio[605]: error: MPD error: The expression evaluated to a falsy value: Feb 22 13:59:48 musicserver volumio[605]: assert.ok(self.idling) Feb 22 13:59:48 musicserver volumio[605]: error: The expression evaluated to a falsy value: Feb 22 13:59:48 musicserver volumio[605]: assert.ok(self.idling) Feb 22 13:59:48 musicserver volumio[605]: info: MPD running with PID822 Feb 22 13:59:48 musicserver volumio[605]: ,establishing connection Feb 22 13:59:48 musicserver volumio[605]: error: updateQueue error: null Feb 22 13:59:48 musicserver volumio[605]: error: updateQueue error: null Feb 22 13:59:48 musicserver go-librespot[850]: time="2024-02-22T13:59:48+02:00" level=debug msg="put connect state because NEW_DEVICE" Feb 22 13:59:49 musicserver volumio[877]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 22 13:59:50 musicserver volumio[605]: info: Initializing connection to go-librespot Websocket Feb 22 13:59:50 musicserver go-librespot[850]: time="2024-02-22T13:59:50+02:00" level=debug msg="new websocket client" Feb 22 13:59:50 musicserver volumio[605]: info: Connection to go-librespot Websocket established Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=debug msg="handling transfer player command from b8d60df07813431fbabe13c2faf3ff136ec5e576" Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=debug msg="loading track spotify:track:1Crj1zkRMpsEjb9NOR6Zof (paused: true, position: 37000ms)" Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=trace msg="emitting websocket event: will_play" Feb 22 13:59:52 musicserver volumio[605]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1Crj1zkRMpsEjb9NOR6Zof","play_origin":"playlist/ondemand"}} Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1Crj1zkRMpsEjb9NOR6Zof" Feb 22 13:59:52 musicserver go-librespot[850]: time="2024-02-22T13:59:52+02:00" level=debug msg="requested aes key for file c39f9fb9e4595896ec5b742849953b993d58f3f0, gid: 1Crj1zkRMpsEjb9NOR6Zof" Feb 22 13:59:53 musicserver volumio[605]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 22 13:59:53 musicserver go-librespot[850]: time="2024-02-22T13:59:53+02:00" level=debug msg="fetched first chunk of 20, total size is 10339644 bytes" Feb 22 13:59:53 musicserver go-librespot[850]: time="2024-02-22T13:59:53+02:00" level=debug msg="fetched chunk 2/19, size: 524288" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="fetched chunk 4/19, size: 524288" Feb 22 13:59:54 musicserver volumio[605]: info: Getting Spotify volume Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="fetched chunk 1/19, size: 524288" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="fetched chunk 5/19, size: 524288" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="fetched chunk 6/19, size: 524288" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="fetched chunk 3/19, size: 524288" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=trace msg="seek to 37000ms (diff: 81ms, samples: 1631700, bytes: 1930963)" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=info msg="loaded track \"L-Gante: Bzrp Music Sessions, Vol.38\" (uri: spotify:track:1Crj1zkRMpsEjb9NOR6Zof, paused: true, position: 37000ms, duration: 192347ms)" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=trace msg="emitting websocket event: metadata" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=trace msg="emitting websocket event: active" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="sending successful reply for delaer request" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 22 13:59:54 musicserver volumio[605]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1582" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=trace msg="emitting websocket event: paused" Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 22 13:59:54 musicserver go-librespot[850]: time="2024-02-22T13:59:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1342" Feb 22 13:59:55 musicserver volumio[605]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1Crj1zkRMpsEjb9NOR6Zof","name":"L-Gante: Bzrp Music Sessions, Vol.38","artist_names":["Bizarrap","L-Gante"],"album_name":"L-Gante: Bzrp Music Sessions, Vol. 38","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dada4e65cefce3bdc16a8dae","position":37000,"duration":192347,"release_date":"year:2021 month:3 day:10","track_number":1,"disc_number":1}} Feb 22 13:59:55 musicserver volumio[605]: SPOTIFY: received: {"type":"active","data":null} Feb 22 13:59:55 musicserver volumio[605]: info: Aligning Spotify Volume to Volumio Volume Feb 22 13:59:55 musicserver volumio[605]: info: CoreCommandRouter::volumioGetState Feb 22 13:59:55 musicserver volumio[605]: info: CorePlayQueue::getTrack 0 Feb 22 13:59:55 musicserver volumio[605]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1Crj1zkRMpsEjb9NOR6Zof","play_origin":"playlist/ondemand"}} Feb 22 13:59:55 musicserver volumio[605]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 13:59:55 musicserver volumio[605]: TypeError: Cannot read property 'service' of undefined Feb 22 13:59:55 musicserver volumio[605]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Feb 22 13:59:55 musicserver volumio[605]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) Feb 22 13:59:55 musicserver volumio[605]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Feb 22 13:59:55 musicserver volumio[605]: at WebSocket.emit (events.js:315:20) Feb 22 13:59:55 musicserver volumio[605]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Feb 22 13:59:55 musicserver volumio[605]: at Receiver.emit (events.js:315:20) Feb 22 13:59:55 musicserver volumio[605]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Feb 22 13:59:55 musicserver volumio[605]: at internal/process/task_queues.js:149:7 Feb 22 13:59:55 musicserver volumio[605]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Feb 22 13:59:55 musicserver volumio[605]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Feb 22 13:59:55 musicserver volumio[605]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Feb 22 13:59:55 musicserver volumio[605]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 13:59:56 musicserver sudo[911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-02-22 13:58 Feb 22 13:59:56 musicserver sudo[911]: 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="9552505bba4239c163ac9ee7b0b87a56e0dd0574" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="3d3fc502273a5c173ba19f72c1a952bdb2bdd3b0" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 Feb 2024 06:28:23 PM CET" VOLUMIO_VERSION="3.616" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b343c71baf05cbc21bf1a530c8e51fc1"