-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sat 2024-11-16 19:23:02 CET. -- Nov 16 19:22:08 volumiopi kernel: usb usb1: Manufacturer: Linux 6.1.69-v7+ dwc_otg_hcd Nov 16 19:22:08 volumiopi kernel: usb usb1: SerialNumber: 3f980000.usb Nov 16 19:22:08 volumiopi kernel: hub 1-0:1.0: USB hub found Nov 16 19:22:08 volumiopi kernel: hub 1-0:1.0: 1 port detected Nov 16 19:22:08 volumiopi kernel: dwc_otg: FIQ enabled Nov 16 19:22:08 volumiopi kernel: dwc_otg: NAK holdoff enabled Nov 16 19:22:08 volumiopi kernel: dwc_otg: FIQ split-transaction FSM enabled Nov 16 19:22:08 volumiopi kernel: Module dwc_common_port init Nov 16 19:22:08 volumiopi kernel: usbcore: registered new interface driver usb-storage Nov 16 19:22:08 volumiopi kernel: mousedev: PS/2 mouse device common for all mice Nov 16 19:22:08 volumiopi kernel: sdhci: Secure Digital Host Controller Interface driver Nov 16 19:22:08 volumiopi kernel: sdhci: Copyright(c) Pierre Ossman Nov 16 19:22:08 volumiopi kernel: sdhci-pltfm: SDHCI platform and OF driver helper Nov 16 19:22:08 volumiopi kernel: ledtrig-cpu: registered to indicate activity on CPUs Nov 16 19:22:08 volumiopi kernel: hid: raw HID events driver (C) Jiri Kosina Nov 16 19:22:08 volumiopi kernel: usbcore: registered new interface driver usbhid Nov 16 19:22:08 volumiopi kernel: usbhid: USB HID core driver Nov 16 19:22:08 volumiopi kernel: Initializing XFRM netlink socket Nov 16 19:22:08 volumiopi kernel: NET: Registered PF_PACKET protocol family Nov 16 19:22:08 volumiopi kernel: Key type dns_resolver registered Nov 16 19:22:08 volumiopi kernel: Registering SWP/SWPB emulation handler Nov 16 19:22:08 volumiopi kernel: registered taskstats version 1 Nov 16 19:22:08 volumiopi kernel: Loading compiled-in X.509 certificates Nov 16 19:22:08 volumiopi kernel: Key type .fscrypt registered Nov 16 19:22:08 volumiopi kernel: Key type fscrypt-provisioning registered Nov 16 19:22:08 volumiopi kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Nov 16 19:22:08 volumiopi kernel: 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2 Nov 16 19:22:08 volumiopi kernel: printk: console [ttyAMA0] enabled Nov 16 19:22:08 volumiopi kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Nov 16 19:22:08 volumiopi kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Nov 16 19:22:08 volumiopi kernel: sdhost: log_buf @ 56a45901 (f4113000) Nov 16 19:22:08 volumiopi kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Nov 16 19:22:08 volumiopi kernel: of_cfs_init Nov 16 19:22:08 volumiopi kernel: of_cfs_init: OK Nov 16 19:22:08 volumiopi kernel: Freeing unused kernel image (initmem) memory: 1024K Nov 16 19:22:08 volumiopi kernel: Indeed it is in host mode hprt0 = 00021501 Nov 16 19:22:08 volumiopi kernel: Run /init as init process Nov 16 19:22:08 volumiopi kernel: with arguments: Nov 16 19:22:08 volumiopi kernel: /init Nov 16 19:22:08 volumiopi kernel: splash Nov 16 19:22:08 volumiopi kernel: nodebug Nov 16 19:22:08 volumiopi kernel: with environment: Nov 16 19:22:08 volumiopi kernel: HOME=/ Nov 16 19:22:08 volumiopi kernel: TERM=linux Nov 16 19:22:08 volumiopi kernel: imgpart=UUID=db7775c5-9234-4b9a-955e-7341a245d498 Nov 16 19:22:08 volumiopi kernel: imgfile=/volumio_current.sqsh Nov 16 19:22:08 volumiopi kernel: bootpart=UUID=F102-DE29 Nov 16 19:22:08 volumiopi kernel: datapart=UUID=4112086d-38d3-4206-a7af-ef93bf4e4008 Nov 16 19:22:08 volumiopi kernel: uuidconfig=cmdline.txt Nov 16 19:22:08 volumiopi kernel: pcie_aspm=off Nov 16 19:22:08 volumiopi kernel: pci=pcie_bus_safe Nov 16 19:22:08 volumiopi kernel: bootdelay=7 Nov 16 19:22:08 volumiopi kernel: use_kmsg=no Nov 16 19:22:08 volumiopi kernel: mmc0: host does not support reading read-only switch, assuming write-enable Nov 16 19:22:08 volumiopi kernel: mmc0: new high speed SDHC card at address 51f1 Nov 16 19:22:08 volumiopi kernel: mmcblk0: mmc0:51f1 SD08G 7.42 GiB Nov 16 19:22:08 volumiopi kernel: mmcblk0: p1 p2 p3 Nov 16 19:22:08 volumiopi kernel: mmcblk0: mmc0:51f1 SD08G 7.42 GiB Nov 16 19:22:08 volumiopi kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Nov 16 19:22:08 volumiopi kernel: Indeed it is in host mode hprt0 = 00001101 Nov 16 19:22:08 volumiopi kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 Nov 16 19:22:08 volumiopi kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Nov 16 19:22:08 volumiopi kernel: hub 1-1:1.0: USB hub found Nov 16 19:22:08 volumiopi kernel: hub 1-1:1.0: 5 ports detected Nov 16 19:22:08 volumiopi kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Nov 16 19:22:08 volumiopi kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Nov 16 19:22:08 volumiopi kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Nov 16 19:22:08 volumiopi kernel: smsc95xx v2.0.0 Nov 16 19:22:08 volumiopi kernel: SMSC LAN8700 usb-001:003:01: attached PHY driver (mii_bus:phy_addr=usb-001:003:01, irq=199) Nov 16 19:22:08 volumiopi kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:40:a4:1b Nov 16 19:22:08 volumiopi kernel: fuse: init (API version 7.37) Nov 16 19:22:08 volumiopi kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Nov 16 19:22:08 volumiopi kernel: usbcore: registered new interface driver uas Nov 16 19:22:08 volumiopi kernel: EXT4-fs (mmcblk0p2): recovery complete Nov 16 19:22:08 volumiopi kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Nov 16 19:22:08 volumiopi kernel: loop0: detected capacity change from 0 to 983360 Nov 16 19:22:08 volumiopi kernel: EXT4-fs (mmcblk0p3): recovery complete Nov 16 19:22:08 volumiopi kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Nov 16 19:22:08 volumiopi systemd[1]: System time before build time, advancing clock. Nov 16 19:22:08 volumiopi kernel: NET: Registered PF_INET6 protocol family Nov 16 19:22:08 volumiopi kernel: Segment Routing with IPv6 Nov 16 19:22:08 volumiopi kernel: In-situ OAM (IOAM) with IPv6 Nov 16 19:22:08 volumiopi 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) Nov 16 19:22:08 volumiopi systemd[1]: Detected architecture arm. Nov 16 19:22:08 volumiopi systemd[1]: Set hostname to . Nov 16 19:22:08 volumiopi kernel: uart-pl011 3f201000.serial: no DMA platform data Nov 16 19:22:08 volumiopi 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. Nov 16 19:22:08 volumiopi systemd[1]: Listening on Journal Audit Socket. Nov 16 19:22:08 volumiopi systemd[1]: Listening on initctl Compatibility Named Pipe. Nov 16 19:22:08 volumiopi systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Nov 16 19:22:08 volumiopi systemd[1]: Listening on udev Control Socket. Nov 16 19:22:08 volumiopi systemd[1]: Created slice system-getty.slice. Nov 16 19:22:08 volumiopi systemd[1]: Listening on Journal Socket. Nov 16 19:22:08 volumiopi kernel: i2c_dev: i2c /dev entries driver Nov 16 19:22:08 volumiopi systemd-journald[291]: Journal started Nov 16 19:22:08 volumiopi systemd-journald[291]: Runtime journal (/run/log/journal/c1d531165394c79721acb5a765d65e88) is 7.5M, max 30.0M, 22.5M free. Nov 16 19:22:08 volumiopi systemd-modules-load[284]: Inserted module 'i2c_dev' Nov 16 19:22:08 volumiopi fake-hwclock[289]: Sat Nov 16 18:22:08 UTC 2024 Nov 16 19:22:08 volumiopi systemd[1]: Mounted Kernel Configuration File System. Nov 16 19:22:08 volumiopi systemd[1]: dynamicswap.service: Succeeded. Nov 16 19:22:08 volumiopi systemd[1]: Started Apply Kernel Variables. Nov 16 19:22:08 volumiopi systemd[1]: Mounted FUSE Control File System. Nov 16 19:22:08 volumiopi systemd[1]: Started Load/Save Random Seed. Nov 16 19:22:08 volumiopi systemd[1]: Started Create System Users. Nov 16 19:22:08 volumiopi systemd[1]: Starting Create Static Device Nodes in /dev... Nov 16 19:22:08 volumiopi systemd[1]: Started Create Static Device Nodes in /dev. Nov 16 19:22:08 volumiopi systemd[1]: Reached target Local File Systems (Pre). Nov 16 19:22:08 volumiopi systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Nov 16 19:22:08 volumiopi systemd[1]: Mounting /var/log... Nov 16 19:22:08 volumiopi systemd[1]: Mounting /var/spool/cups... Nov 16 19:22:08 volumiopi systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Nov 16 19:22:08 volumiopi systemd[1]: Mounting /tmp... Nov 16 19:22:08 volumiopi systemd[1]: Starting udev Kernel Device Manager... Nov 16 19:22:08 volumiopi systemd[1]: Started udev Coldplug all Devices. Nov 16 19:22:08 volumiopi systemd[1]: Mounted /var/log. Nov 16 19:22:08 volumiopi systemd[1]: Mounted /var/spool/cups. Nov 16 19:22:08 volumiopi systemd[1]: Mounted /tmp. Nov 16 19:22:08 volumiopi systemd[1]: Mounting /var/spool/cups/tmp... Nov 16 19:22:08 volumiopi systemd[1]: Starting Flush Journal to Persistent Storage... Nov 16 19:22:08 volumiopi systemd[1]: Starting Helper to synchronize boot up for ifupdown... Nov 16 19:22:08 volumiopi systemd[1]: Mounted /var/spool/cups/tmp. Nov 16 19:22:09 volumiopi systemd-journald[291]: Runtime journal (/run/log/journal/c1d531165394c79721acb5a765d65e88) is 7.5M, max 30.0M, 22.5M free. Nov 16 19:22:09 volumiopi systemd[1]: Started Flush Journal to Persistent Storage. Nov 16 19:22:10 volumiopi systemd-udevd[322]: Network interface NamePolicy= disabled on kernel command line, ignoring. Nov 16 19:22:10 volumiopi systemd[1]: Started Helper to synchronize boot up for ifupdown. Nov 16 19:22:10 volumiopi systemd[1]: Started udev Kernel Device Manager. Nov 16 19:22:10 volumiopi systemd[1]: Starting Show Plymouth Boot Screen... Nov 16 19:22:10 volumiopi systemd[1]: plymouth-start.service: Succeeded. Nov 16 19:22:10 volumiopi systemd[1]: Started Show Plymouth Boot Screen. Nov 16 19:22:10 volumiopi systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Nov 16 19:22:10 volumiopi systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 16 19:22:10 volumiopi systemd[1]: Reached target Paths. Nov 16 19:22:10 volumiopi systemd[1]: Reached target Local Encrypted Volumes. Nov 16 19:22:10 volumiopi kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:10 volumiopi kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Nov 16 19:22:10 volumiopi kernel: [vc_sm_connected_init]: start Nov 16 19:22:10 volumiopi kernel: mc: Linux media interface: v0.10 Nov 16 19:22:10 volumiopi kernel: [vc_sm_connected_init]: installed successfully Nov 16 19:22:10 volumiopi kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Nov 16 19:22:10 volumiopi kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Nov 16 19:22:11 volumiopi systemd[1]: Found device /dev/ttyAMA0. Nov 16 19:22:11 volumiopi kernel: videodev: Linux video capture interface: v2.00 Nov 16 19:22:11 volumiopi kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:11 volumiopi kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Nov 16 19:22:11 volumiopi systemd-udevd[334]: Using default interface naming scheme 'v240'. Nov 16 19:22:11 volumiopi kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 16 19:22:11 volumiopi kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 16 19:22:11 volumiopi systemd-udevd[334]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 16 19:22:11 volumiopi kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:11 volumiopi kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:11 volumiopi kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:11 volumiopi kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:11 volumiopi kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 16 19:22:11 volumiopi kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Nov 16 19:22:11 volumiopi kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Nov 16 19:22:12 volumiopi kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Nov 16 19:22:12 volumiopi systemd-udevd[328]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 16 19:22:12 volumiopi systemd[1]: Found device /dev/disk/by-uuid/F102-DE29. Nov 16 19:22:13 volumiopi kernel: wm8804 1-003b: revision E Nov 16 19:22:13 volumiopi systemd[1]: Condition check resulted in SMSC9512/9514 Fast Ethernet Adapter being skipped. Nov 16 19:22:13 volumiopi systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Nov 16 19:22:13 volumiopi systemd[1]: Starting Show Plymouth Boot Screen... Nov 16 19:22:13 volumiopi systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Nov 16 19:22:13 volumiopi systemd[1]: Condition check resulted in Huge Pages File System being skipped. Nov 16 19:22:13 volumiopi systemd[1]: Starting File System Check on /dev/disk/by-uuid/F102-DE29... Nov 16 19:22:14 volumiopi systemd[1]: plymouth-start.service: Succeeded. Nov 16 19:22:14 volumiopi systemd[1]: Started Show Plymouth Boot Screen. Nov 16 19:22:14 volumiopi systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 16 19:22:14 volumiopi systemd[1]: Started File System Check Daemon to report status. Nov 16 19:22:14 volumiopi systemd-fsck[424]: fsck.fat 4.1 (2017-01-24) Nov 16 19:22:14 volumiopi systemd-fsck[424]: /dev/mmcblk0p1: 373 files, 33702/46774 clusters Nov 16 19:22:14 volumiopi systemd[1]: Started File System Check on /dev/disk/by-uuid/F102-DE29. Nov 16 19:22:14 volumiopi systemd[1]: Mounting /boot... Nov 16 19:22:14 volumiopi systemd[1]: Mounted /boot. Nov 16 19:22:14 volumiopi systemd[1]: Reached target Local File Systems. Nov 16 19:22:14 volumiopi systemd[1]: Started ifup for eth0. Nov 16 19:22:14 volumiopi systemd[1]: Starting Create Volatile Files and Directories... Nov 16 19:22:14 volumiopi systemd[1]: Starting Preprocess NFS configuration... Nov 16 19:22:14 volumiopi systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Nov 16 19:22:14 volumiopi systemd[1]: Starting Raise network interfaces... Nov 16 19:22:14 volumiopi systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Nov 16 19:22:14 volumiopi systemd[1]: nfs-config.service: Succeeded. Nov 16 19:22:14 volumiopi systemd[1]: Started Preprocess NFS configuration. Nov 16 19:22:14 volumiopi systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Nov 16 19:22:14 volumiopi systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Nov 16 19:22:14 volumiopi systemd[1]: Reached target NFS client services. Nov 16 19:22:14 volumiopi systemd[1]: Received SIGRTMIN+20 from PID 180 (plymouthd). Nov 16 19:22:14 volumiopi systemd[1]: plymouth-read-write.service: Succeeded. Nov 16 19:22:14 volumiopi systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Nov 16 19:22:14 volumiopi systemd[1]: Started Create Volatile Files and Directories. Nov 16 19:22:14 volumiopi systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Nov 16 19:22:15 volumiopi systemd[1]: Starting RPC bind portmap service... Nov 16 19:22:15 volumiopi systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Nov 16 19:22:15 volumiopi systemd[1]: Starting Update UTMP about System Boot/Shutdown... Nov 16 19:22:15 volumiopi kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Nov 16 19:22:15 volumiopi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Nov 16 19:22:15 volumiopi systemd[1]: Started Update UTMP about System Boot/Shutdown. Nov 16 19:22:15 volumiopi systemd[1]: Reached target System Initialization. Nov 16 19:22:15 volumiopi kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Nov 16 19:22:15 volumiopi kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Nov 16 19:22:15 volumiopi kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Nov 16 19:22:15 volumiopi systemd[1]: Listening on D-Bus System Message Bus Socket. Nov 16 19:22:15 volumiopi systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Nov 16 19:22:15 volumiopi systemd[1]: Started Daily apt download activities. Nov 16 19:22:15 volumiopi systemd[1]: Started Daily apt upgrade and clean activities. Nov 16 19:22:15 volumiopi systemd[1]: Listening on triggerhappy.socket. Nov 16 19:22:15 volumiopi systemd[1]: Reached target Sockets. Nov 16 19:22:15 volumiopi systemd[1]: Reached target Basic System. Nov 16 19:22:15 volumiopi systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Nov 16 19:22:15 volumiopi ifup[442]: command failed: No such device (-19) Nov 16 19:22:15 volumiopi sh[437]: command failed: No such device (-19) Nov 16 19:22:15 volumiopi systemd[1]: Started D-Bus System Message Bus. Nov 16 19:22:15 volumiopi systemd[1]: Started volumio-remote-updater.service. Nov 16 19:22:15 volumiopi systemd[1]: Starting Wireless Services... Nov 16 19:22:15 volumiopi systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Nov 16 19:22:15 volumiopi systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Nov 16 19:22:15 volumiopi systemd[1]: Condition check resulted in Configure Bluetooth Modems connected by UART being skipped. Nov 16 19:22:15 volumiopi systemd[1]: Starting WPA supplicant... Nov 16 19:22:15 volumiopi systemd[1]: Starting Login Service... Nov 16 19:22:15 volumiopi systemd[1]: Started Manage Sound Card State (restore and store). Nov 16 19:22:15 volumiopi alsactl[507]: alsactl 1.1.8 daemon started Nov 16 19:22:15 volumiopi systemd[1]: Starting Save/Restore Sound Card State... Nov 16 19:22:15 volumiopi systemd[1]: Started UPnP Renderer front-end to MPD. Nov 16 19:22:16 volumiopi systemd[1]: Starting triggerhappy global hotkey daemon... Nov 16 19:22:16 volumiopi systemd[1]: Started Volumio Log Rotation Service. Nov 16 19:22:16 volumiopi systemd[1]: Started Daily Cleanup of Temporary Directories. Nov 16 19:22:16 volumiopi systemd[1]: Reached target Timers. Nov 16 19:22:16 volumiopi ifup[442]: command failed: No such device (-19) Nov 16 19:22:16 volumiopi systemd[1]: Started Volumio Iptables Module. Nov 16 19:22:16 volumiopi thd[516]: Unable to parse trigger line: Nov 16 19:22:16 volumiopi thd[516]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Nov 16 19:22:16 volumiopi thd[516]: Unable to parse trigger line: Nov 16 19:22:16 volumiopi thd[516]: Unable to parse trigger line: Nov 16 19:22:16 volumiopi thd[516]: Found socket passed from systemd Nov 16 19:22:16 volumiopi systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Nov 16 19:22:16 volumiopi avahi-daemon[498]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Nov 16 19:22:16 volumiopi avahi-daemon[498]: Successfully dropped root privileges. Nov 16 19:22:16 volumiopi systemd[1]: Starting dhcpcd on all interfaces... Nov 16 19:22:16 volumiopi avahi-daemon[498]: avahi-daemon 0.7 starting up. Nov 16 19:22:16 volumiopi systemd[1]: Started RPC bind portmap service. Nov 16 19:22:16 volumiopi systemd[1]: Started triggerhappy global hotkey daemon. Nov 16 19:22:16 volumiopi systemd[1]: Started Save/Restore Sound Card State. Nov 16 19:22:16 volumiopi systemd[1]: Reached target Sound Card. Nov 16 19:22:16 volumiopi systemd[1]: Reached target RPC Port Mapper. Nov 16 19:22:16 volumiopi systemd[1]: Reached target Remote File Systems (Pre). Nov 16 19:22:16 volumiopi systemd[1]: Reached target Remote File Systems. Nov 16 19:22:16 volumiopi systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Nov 16 19:22:16 volumiopi dhcpcd[524]: Not running dhcpcd because /etc/network/interfaces Nov 16 19:22:16 volumiopi dhcpcd[524]: defines some interfaces that will use a Nov 16 19:22:16 volumiopi dhcpcd[524]: DHCP client or static address Nov 16 19:22:16 volumiopi systemd-logind[503]: New seat seat0. Nov 16 19:22:16 volumiopi kernel: 8021q: 802.1Q VLAN Support v1.8 Nov 16 19:22:17 volumiopi avahi-daemon[498]: Successfully called chroot(). Nov 16 19:22:17 volumiopi avahi-daemon[498]: Successfully dropped remaining capabilities. Nov 16 19:22:17 volumiopi systemd[1]: Started Login Service. Nov 16 19:22:17 volumiopi systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Nov 16 19:22:17 volumiopi systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Nov 16 19:22:17 volumiopi systemd[1]: Failed to start dhcpcd on all interfaces. Nov 16 19:22:17 volumiopi wpa_supplicant[500]: Successfully initialized wpa_supplicant Nov 16 19:22:17 volumiopi avahi-daemon[498]: Loading service file /services/volumio.service. Nov 16 19:22:17 volumiopi avahi-daemon[498]: Network interface enumeration completed. Nov 16 19:22:17 volumiopi avahi-daemon[498]: Server startup complete. Host name is volumiopi.local. Local service cookie is 2373566197. Nov 16 19:22:17 volumiopi avahi-daemon[498]: Service "VolumioPi" (/services/volumio.service) successfully established. Nov 16 19:22:18 volumiopi sh[437]: eth0: waiting for carrier Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: waiting for carrier Nov 16 19:22:18 volumiopi kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Nov 16 19:22:18 volumiopi kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Nov 16 19:22:18 volumiopi sh[437]: eth0: carrier acquired Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: carrier acquired Nov 16 19:22:18 volumiopi systemd[1]: Started Avahi mDNS/DNS-SD Stack. Nov 16 19:22:18 volumiopi systemd[1]: Started WPA supplicant. Nov 16 19:22:18 volumiopi sh[437]: DUID 00:01:00:01:2d:69:1e:61:b8:27:eb:40:a4:1b Nov 16 19:22:18 volumiopi sh[437]: eth0: IAID eb:40:a4:1b Nov 16 19:22:18 volumiopi dhcpcd[497]: DUID 00:01:00:01:2d:69:1e:61:b8:27:eb:40:a4:1b Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: IAID eb:40:a4:1b Nov 16 19:22:18 volumiopi sh[437]: eth0: adding address fe80::d335:8953:77f1:52a Nov 16 19:22:18 volumiopi sh[437]: ipv6_addaddr1: Permission denied Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: adding address fe80::d335:8953:77f1:52a Nov 16 19:22:18 volumiopi dhcpcd[497]: ipv6_addaddr1: Permission denied Nov 16 19:22:18 volumiopi volumio-remote-updater[492]: Error: No active session Nov 16 19:22:18 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:18] [info] asio async_connect error: system:111 (Connection refused) Nov 16 19:22:18 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:18] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 16 19:22:18 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:18] [error] handle_connect error: Underlying Transport Error Nov 16 19:22:18 volumiopi sh[437]: eth0: soliciting an IPv6 router Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: soliciting an IPv6 router Nov 16 19:22:18 volumiopi sh[437]: eth0: soliciting a DHCP lease Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: soliciting a DHCP lease Nov 16 19:22:18 volumiopi systemd[1]: Started Raise network interfaces. Nov 16 19:22:18 volumiopi systemd[1]: Reached target Network. Nov 16 19:22:18 volumiopi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Nov 16 19:22:18 volumiopi sh[437]: eth0: offered 192.168.100.20 from 192.168.100.1 Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: offered 192.168.100.20 from 192.168.100.1 Nov 16 19:22:18 volumiopi sh[437]: eth0: probing address 192.168.100.20/24 Nov 16 19:22:18 volumiopi dhcpcd[497]: eth0: probing address 192.168.100.20/24 Nov 16 19:22:18 volumiopi volumio[513]: Could not open config: /tmp/upmpdcli.conf Nov 16 19:22:18 volumiopi systemd[1]: Starting Network Time Service... Nov 16 19:22:18 volumiopi systemd[1]: Starting Permit User Sessions... Nov 16 19:22:18 volumiopi systemd[1]: Reached target Network is Online. Nov 16 19:22:18 volumiopi systemd[1]: Starting /etc/rc.local Compatibility... Nov 16 19:22:18 volumiopi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 16 19:22:18 volumiopi systemd[1]: Starting Samba NMB Daemon... Nov 16 19:22:18 volumiopi systemd[1]: Starting LSB: Brings up/down network automatically... Nov 16 19:22:18 volumiopi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Nov 16 19:22:18 volumiopi systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 16 19:22:18 volumiopi systemd[1]: Started Permit User Sessions. Nov 16 19:22:18 volumiopi systemd[1]: Started /etc/rc.local Compatibility. Nov 16 19:22:18 volumiopi systemd[1]: iptables.service: Succeeded. Nov 16 19:22:19 volumiopi systemd[1]: Starting Terminate Plymouth Boot Screen... Nov 16 19:22:19 volumiopi systemd[1]: Starting Hold until boot process finishes up... Nov 16 19:22:19 volumiopi haveged[465]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Nov 16 19:22:19 volumiopi haveged[465]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Nov 16 19:22:19 volumiopi haveged[465]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99814 Nov 16 19:22:19 volumiopi haveged[465]: haveged: fills: 0, generated: 0 Nov 16 19:22:19 volumiopi systemd[1]: plymouth-quit.service: Succeeded. Nov 16 19:22:19 volumiopi systemd[1]: Started Terminate Plymouth Boot Screen. Nov 16 19:22:19 volumiopi systemd[1]: plymouth-quit-wait.service: Succeeded. Nov 16 19:22:19 volumiopi systemd[1]: Started Hold until boot process finishes up. Nov 16 19:22:19 volumiopi systemd[1]: Received SIGRTMIN+21 from PID 180 (n/a). Nov 16 19:22:19 volumiopi systemd[1]: Received SIGRTMIN+21 from PID 180 (n/a). Nov 16 19:22:19 volumiopi loadcpufreq[528]: Loading cpufreq kernel modules...done (none). Nov 16 19:22:19 volumiopi systemd[1]: Started Getty on tty1. Nov 16 19:22:19 volumiopi systemd[1]: Started Serial Getty on ttyAMA0. Nov 16 19:22:19 volumiopi systemd[1]: Reached target Login Prompts. Nov 16 19:22:19 volumiopi systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Nov 16 19:22:19 volumiopi systemd[1]: Starting LSB: set CPUFreq kernel parameters... Nov 16 19:22:19 volumiopi ntpd[599]: ntpd 4.2.8p12@1.3728-o (1): Starting Nov 16 19:22:19 volumiopi ntpd[599]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Nov 16 19:22:19 volumiopi systemd[1]: Started Network Time Service. Nov 16 19:22:19 volumiopi ifplugd(eth0)[663]: ifplugd 0.28 initializing. Nov 16 19:22:19 volumiopi ifplugd(eth0)[663]: Using interface eth0/B8:27:EB:40:A4:1B with driver (version: 6.1.69-v7+) Nov 16 19:22:19 volumiopi ifplugd(eth0)[663]: Using detection mode: SIOCETHTOOL Nov 16 19:22:19 volumiopi ifplugd(eth0)[663]: Initialization complete, link beat detected. Nov 16 19:22:19 volumiopi ntpd[656]: proto: precision = 1.666 usec (-19) Nov 16 19:22:19 volumiopi ntpd[656]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Nov 16 19:22:19 volumiopi ntpd[656]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 16 19:22:19 volumiopi ntpd[656]: Listen and drop on 0 v6wildcard [::]:123 Nov 16 19:22:19 volumiopi ntpd[656]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Nov 16 19:22:19 volumiopi ntpd[656]: Listen normally on 2 lo 127.0.0.1:123 Nov 16 19:22:19 volumiopi ntpd[656]: Listening on routing socket on fd #19 for interface updates Nov 16 19:22:19 volumiopi ntpd[656]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 16 19:22:19 volumiopi ntpd[656]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 16 19:22:19 volumiopi ifplugd(eth0)[663]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Nov 16 19:22:20 volumiopi ifplugd(eth0)[663]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Nov 16 19:22:20 volumiopi cpufrequtils[655]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Nov 16 19:22:20 volumiopi systemd[1]: Started LSB: set CPUFreq kernel parameters. Nov 16 19:22:20 volumiopi ntpd[656]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 16 19:22:21 volumiopi nmbd[616]: [2024/11/16 19:22:21.214688, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Nov 16 19:22:21 volumiopi nmbd[616]: started asyncdns process 680 Nov 16 19:22:21 volumiopi nmbd[616]: [2024/11/16 19:22:21.219631, 0] ../lib/util/become_daemon.c:149(daemon_status) Nov 16 19:22:21 volumiopi nmbd[616]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Nov 16 19:22:21 volumiopi nmbd[616]: [2024/11/16 19:22:21.220027, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Nov 16 19:22:21 volumiopi nmbd[616]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Nov 16 19:22:21 volumiopi ntpd[656]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 16 19:22:21 volumiopi wireless.js[495]: WIRELESS: No wireless interface, exiting Nov 16 19:22:22 volumiopi iw[685]: command failed: No such device (-19) Nov 16 19:22:22 volumiopi iwconfig[688]: Error for wireless request "Set Power Management" (8B2C) : Nov 16 19:22:22 volumiopi iwconfig[688]: SET failed on device wlan0 ; No such device. Nov 16 19:22:22 volumiopi systemd[1]: wireless.service: Succeeded. Nov 16 19:22:22 volumiopi systemd[1]: Started Wireless Services. Nov 16 19:22:22 volumiopi systemd[1]: Started Volumio Backend Module. Nov 16 19:22:22 volumiopi systemd[1]: Started Volumio Cpu Tweaker. Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: Setting RT Priority for mpd Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: pid 35's current scheduling policy: SCHED_OTHER Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: pid 35's current scheduling priority: 0 Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: Setting MPD Affinity Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: pid 3's current affinity mask: f Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Nov 16 19:22:22 volumiopi volumio-cpu-tweak[692]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Nov 16 19:22:22 volumiopi systemd[1]: volumio_cpu_tweak.service: Succeeded. Nov 16 19:22:22 volumiopi ntpd[656]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 16 19:22:23 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:23] [info] asio async_connect error: system:111 (Connection refused) Nov 16 19:22:23 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:23] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 16 19:22:23 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:23] [error] handle_connect error: Underlying Transport Error Nov 16 19:22:23 volumiopi sh[437]: eth0: leased 192.168.100.20 for 86400 seconds Nov 16 19:22:23 volumiopi dhcpcd[497]: eth0: leased 192.168.100.20 for 86400 seconds Nov 16 19:22:23 volumiopi ntpd[656]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 16 19:22:24 volumiopi avahi-daemon[498]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.100.20. Nov 16 19:22:24 volumiopi dhcpcd[497]: eth0: adding route to 192.168.100.0/24 Nov 16 19:22:24 volumiopi sh[437]: eth0: adding route to 192.168.100.0/24 Nov 16 19:22:24 volumiopi sh[437]: eth0: adding default route via 192.168.100.1 Nov 16 19:22:24 volumiopi avahi-daemon[498]: New relevant interface eth0.IPv4 for mDNS. Nov 16 19:22:24 volumiopi avahi-daemon[498]: Registering new address record for 192.168.100.20 on eth0.IPv4. Nov 16 19:22:24 volumiopi dhcpcd[497]: eth0: adding default route via 192.168.100.1 Nov 16 19:22:25 volumiopi sh[437]: forked to background, child pid 728 Nov 16 19:22:25 volumiopi dhcpcd[497]: forked to background, child pid 728 Nov 16 19:22:25 volumiopi ifplugd(eth0)[663]: client: ifup: interface eth0 already configured Nov 16 19:22:25 volumiopi sh[437]: eth0=eth0 Nov 16 19:22:25 volumiopi ifplugd(eth0)[663]: Program executed successfully. Nov 16 19:22:25 volumiopi ifplugd[607]: Network Interface Plugging Daemon...start eth0...done. Nov 16 19:22:25 volumiopi systemd[1]: Started LSB: Brings up/down network automatically. Nov 16 19:22:25 volumiopi ntpd[656]: Listen normally on 3 eth0 192.168.100.20:123 Nov 16 19:22:25 volumiopi ntpd[656]: new interface(s) found: waking up resolver Nov 16 19:22:26 volumiopi nmbd[616]: [2024/11/16 19:22:26.463168, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 16 19:22:26 volumiopi nmbd[616]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 16 19:22:26 volumiopi systemd[1]: Started Samba NMB Daemon. Nov 16 19:22:26 volumiopi systemd[1]: Starting Samba Winbind Daemon... Nov 16 19:22:27 volumiopi winbindd[754]: [2024/11/16 19:22:27.092276, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 16 19:22:27 volumiopi winbindd[754]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 16 19:22:27 volumiopi winbindd[754]: [2024/11/16 19:22:27.649413, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 16 19:22:27 volumiopi systemd[1]: Started Samba Winbind Daemon. Nov 16 19:22:27 volumiopi winbindd[754]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 16 19:22:27 volumiopi systemd[1]: Starting Samba SMB Daemon... Nov 16 19:22:30 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:30] [connect] Successful connection Nov 16 19:22:32 volumiopi smbd[759]: [2024/11/16 19:22:32.839271, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 16 19:22:32 volumiopi smbd[759]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 16 19:22:32 volumiopi systemd[1]: Started Samba SMB Daemon. Nov 16 19:22:32 volumiopi systemd[1]: Reached target Multi-User System. Nov 16 19:22:32 volumiopi systemd[1]: Reached target Graphical Interface. Nov 16 19:22:32 volumiopi systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 16 19:22:32 volumiopi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 16 19:22:32 volumiopi systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 16 19:22:32 volumiopi systemd[1]: Startup finished in 19.646s (kernel) + 27.919s (userspace) = 47.566s. Nov 16 19:22:34 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:34 volumiopi volumio[691]: info: ----- Volumio3 ---- Nov 16 19:22:34 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:34 volumiopi volumio[691]: info: ----- System startup ---- Nov 16 19:22:34 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:36 volumiopi volumio[691]: info: MYVOLUMIO Environment detected Nov 16 19:22:37 volumiopi volumio[691]: info: Plugin folders cleanup Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning into folder /volumio/app/plugins/ Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category audio_interface Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category miscellanea Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category music_service Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category plugins.json Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category system_controller Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category user_interface Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning into folder /data/plugins/ Nov 16 19:22:37 volumiopi volumio[691]: info: Scanning category music_service Nov 16 19:22:37 volumiopi volumio[691]: info: Plugin folders cleanup completed Nov 16 19:22:37 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:37 volumiopi volumio[691]: info: ----- Core plugins startup ---- Nov 16 19:22:37 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:37 volumiopi volumio[691]: info: Loading plugins from folder /volumio/app/plugins/ Nov 16 19:22:37 volumiopi volumio[691]: info: Adding plugin upnp to MyMusic Plugins Nov 16 19:22:37 volumiopi volumio[691]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 16 19:22:37 volumiopi volumio[691]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 16 19:22:37 volumiopi volumio[691]: info: Loading plugins from folder /data/plugins/ Nov 16 19:22:37 volumiopi volumio[691]: info: Loading plugin "system"... Nov 16 19:22:37 volumiopi volumio[691]: info: Loading plugin "appearance"... Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "network"... Nov 16 19:22:41 volumiopi volumio[691]: info: Refreshing Cached IP Addresses Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "services"... Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "alsa_controller"... Nov 16 19:22:41 volumiopi sudo[782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 16 19:22:41 volumiopi sudo[786]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 16 19:22:41 volumiopi sudo[782]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:41 volumiopi sudo[786]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:41 volumiopi sudo[784]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 16 19:22:41 volumiopi sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:41 volumiopi sudo[782]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:41 volumiopi sudo[786]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:41 volumiopi sudo[784]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:41 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "wizard"... Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "networkfs"... Nov 16 19:22:41 volumiopi volumio[691]: info: Starting Udev Watcher for removable devices Nov 16 19:22:41 volumiopi sudo[797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=garfie,password=kociamber,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.100.3/Multimedia/muzyka /mnt/NAS/Kubus Nov 16 19:22:41 volumiopi sudo[797]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:41 volumiopi volumio[691]: info: Ignoring mount for partition: boot Nov 16 19:22:41 volumiopi volumio[691]: info: Ignoring mount for partition: volumio Nov 16 19:22:41 volumiopi volumio[691]: info: Ignoring mount for partition: volumio_data Nov 16 19:22:41 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "volumio_command_line_client"... Nov 16 19:22:41 volumiopi volumio[691]: info: Plugin upnp is not enabled Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "my_music"... Nov 16 19:22:41 volumiopi volumio[691]: info: Loading plugin "mpd"... Nov 16 19:22:42 volumiopi kernel: Key type cifs.spnego registered Nov 16 19:22:42 volumiopi kernel: Key type cifs.idmap registered Nov 16 19:22:42 volumiopi 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. Nov 16 19:22:42 volumiopi kernel: CIFS: Attempting to mount \\192.168.100.3\Multimedia Nov 16 19:22:42 volumiopi sudo[797]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:42 volumiopi volumio[691]: info: Plugin upnp_browser is not enabled Nov 16 19:22:42 volumiopi volumio[691]: info: Loading plugin "alarm-clock"... Nov 16 19:22:43 volumiopi volumio[691]: info: Plugin airplay_emulation is not enabled Nov 16 19:22:43 volumiopi volumio[691]: info: Loading plugin "last_100"... Nov 16 19:22:43 volumiopi volumio[691]: info: Loading plugin "webradio"... Nov 16 19:22:43 volumiopi volumio[691]: info: Loading plugin "i2s_dacs"... Nov 16 19:22:43 volumiopi volumio[691]: info: Loading plugin "volumiodiscovery"... Nov 16 19:22:43 volumiopi volumio[691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 16 19:22:43 volumiopi volumio[691]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 16 19:22:43 volumiopi volumio[691]: *** WARNING *** For more information see Nov 16 19:22:43 volumiopi volumio[691]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 16 19:22:43 volumiopi volumio[691]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 16 19:22:43 volumiopi volumio[691]: *** WARNING *** For more information see Nov 16 19:22:43 volumiopi node[691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 16 19:22:43 volumiopi node[691]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 16 19:22:43 volumiopi node[691]: *** WARNING *** For more information see Nov 16 19:22:43 volumiopi node[691]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 16 19:22:43 volumiopi node[691]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 16 19:22:43 volumiopi node[691]: *** WARNING *** For more information see Nov 16 19:22:43 volumiopi volumio[691]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 16 19:22:43 volumiopi volumio[691]: info: Discovery: Started advertising with name: VolumioPi Nov 16 19:22:43 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 16 19:22:43 volumiopi volumio[691]: info: Loading plugin "spop"... Nov 16 19:22:44 volumiopi systemd[1]: systemd-fsckd.service: Succeeded. Nov 16 19:22:45 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:45] [connect] Successful connection Nov 16 19:22:48 volumiopi volumio[691]: info: Loading plugin "outputs"... Nov 16 19:22:48 volumiopi volumio[691]: info: Loading plugin "albumart"... Nov 16 19:22:48 volumiopi volumio[691]: info: Plugin example_plugin is not enabled Nov 16 19:22:48 volumiopi volumio[691]: info: Loading plugin "inputs"... Nov 16 19:22:48 volumiopi volumio[691]: info: Loading plugin "updater_comm"... Nov 16 19:22:48 volumiopi volumio[691]: info: Plugin mpdemulation is not enabled Nov 16 19:22:48 volumiopi volumio[691]: info: Loading plugin "rest_api"... Nov 16 19:22:48 volumiopi volumio[691]: info: Loading plugin "websocket"... Nov 16 19:22:48 volumiopi volumio[691]: info: Starting Socket.io Server version 2.3.0 Nov 16 19:22:48 volumiopi volumio[691]: info: Loading i18n strings for locale pl Nov 16 19:22:48 volumiopi volumio[691]: Updating browse sources language Nov 16 19:22:48 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 16 19:22:49 volumiopi volumio[691]: Forking 3 albumart workers Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::initPlayerControls Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 16 19:22:49 volumiopi volumio[691]: Express server listening on port 3000 Nov 16 19:22:49 volumiopi volumio[691]: [Metrics] WebUI: 20s 675.07ms Nov 16 19:22:49 volumiopi volumio[691]: info: CoreStateMachine::resetVolumioState Nov 16 19:22:49 volumiopi volumio[691]: info: CoreStateMachine::getcurrentVolume Nov 16 19:22:49 volumiopi volumio[691]: info: CoreCommandRouter::volumioRetrievevolume Nov 16 19:22:49 volumiopi volumio[691]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Nov 16 19:22:49 volumiopi volumio[691]: wlan0 Interface doesn't support scanning. Nov 16 19:22:49 volumiopi volumio[691]: info: Cannot use regular scanning, forcing with ap-force Nov 16 19:22:49 volumiopi sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Nov 16 19:22:49 volumiopi sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:50 volumiopi sudo[867]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:50 volumiopi volumio[691]: command failed: No such device (-19) Nov 16 19:22:50 volumiopi volumio[691]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Nov 16 19:22:50 volumiopi volumio[691]: command failed: No such device (-19) Nov 16 19:22:50 volumiopi volumio-remote-updater[492]: [2024-11-16 19:22:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1731781365 101 Nov 16 19:22:50 volumiopi volumio[691]: 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 Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::pushState Nov 16 19:22:50 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::volumioPushState Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::updateTrackBlock Nov 16 19:22:50 volumiopi volumio[691]: info: CorePlayQueue::getTrackBlock Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::volumioRetrievevolume Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 16 19:22:50 volumiopi volumio[691]: info: Reloading queue from file Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::setRepeat true single undefined Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::pushState Nov 16 19:22:50 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::volumioPushState Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::setRandom false Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::pushState Nov 16 19:22:50 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::volumioPushState Nov 16 19:22:50 volumiopi volumio[691]: info: Setting Device type: Raspberry PI Nov 16 19:22:50 volumiopi volumio[691]: info: Completed loading Core Plugins Nov 16 19:22:50 volumiopi volumio[691]: info: Preparing to generate the ALSA configuration file Nov 16 19:22:50 volumiopi volumio[691]: info: CoreStateMachine::pushState Nov 16 19:22:50 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:22:50 volumiopi volumio[691]: info: CoreCommandRouter::volumioPushState Nov 16 19:22:50 volumiopi volumio[691]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 16 19:22:50 volumiopi volumio[691]: info: Reading ALSA contributions from plugins. Nov 16 19:22:50 volumiopi volumio[691]: info: Asound.conf file unchanged, so no further update is needed Nov 16 19:22:50 volumiopi volumio[691]: info: Output device has changed, restarting MPD Nov 16 19:22:50 volumiopi volumio[691]: info: ___________ START PLUGINS ___________ Nov 16 19:22:50 volumiopi volumio[691]: info: ControllerMpd::onStart: Initializing MPD Nov 16 19:22:50 volumiopi volumio[691]: info: Creating MPD Configuration file Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 16 19:22:51 volumiopi volumio[691]: info: [1731781371061] CoreMusicLibrary::Adding element Last_100 Nov 16 19:22:51 volumiopi sudo[884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 16 19:22:51 volumiopi sudo[884]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 16 19:22:51 volumiopi volumio[691]: info: [1731781371089] CoreMusicLibrary::Adding element Webradio Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 16 19:22:51 volumiopi sudo[884]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:51 volumiopi sudo[885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 16 19:22:51 volumiopi volumio[691]: info: Initializing BBC Radios Nov 16 19:22:51 volumiopi sudo[887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 16 19:22:51 volumiopi sudo[887]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:51 volumiopi sudo[885]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:51 volumiopi sudo[887]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:51 volumiopi volumio[691]: Starting albumart workers Nov 16 19:22:51 volumiopi volumio[691]: Starting albumart workers Nov 16 19:22:51 volumiopi sudo[890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 16 19:22:51 volumiopi sudo[890]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 16 19:22:51 volumiopi systemd[1]: Listening on mpd.socket. Nov 16 19:22:51 volumiopi systemd[1]: Starting Music Player Daemon... Nov 16 19:22:51 volumiopi systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 16 19:22:51 volumiopi systemd[1]: mpd.service: Succeeded. Nov 16 19:22:51 volumiopi systemd[1]: Stopped Music Player Daemon. Nov 16 19:22:51 volumiopi systemd[1]: Starting Music Player Daemon... Nov 16 19:22:51 volumiopi volumio[691]: info: Creating Spotify config file Nov 16 19:22:51 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:51 volumiopi volumio[691]: Starting albumart workers Nov 16 19:22:51 volumiopi volumio[691]: info: Volumio Calling Home Nov 16 19:22:51 volumiopi sudo[906]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 16 19:22:51 volumiopi sudo[906]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:51 volumiopi sudo[906]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Nov 16 19:22:51 volumiopi sudo[906]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:52 volumiopi volumio[691]: info: Discovery: adding 997297c0-1552-42fd-9ddb-c07b012ef5e5 Nov 16 19:22:52 volumiopi volumio[691]: info: Discovery: Found device VolumioPi Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::volumioGetState Nov 16 19:22:52 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:22:52 volumiopi volumio[691]: info: MPD Permissions set Nov 16 19:22:52 volumiopi volumio[691]: info: MPD Permissions set Nov 16 19:22:52 volumiopi volumio[691]: info: Spotify config file written Nov 16 19:22:52 volumiopi volumio[691]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 16 19:22:52 volumiopi volumio[691]: info: Volumio called home Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi sudo[913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi sudo[913]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi systemd[1]: Started go-librespot Daemon. Nov 16 19:22:52 volumiopi go-librespot[919]: Librespot-go daemon starting... Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi sudo[913]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 16 19:22:52 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 16 19:22:53 volumiopi volumio[691]: info: CoreCommandRouter::volumioGetState Nov 16 19:22:53 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:22:53 volumiopi volumio[691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 16 19:22:53 volumiopi volumio[691]: SPOTIFY: BQD-6ZJ3hVI0DNbzlJ7SGiUcT226bsDpZc49Fbn8XRfr0AH8mxKN_717VLs6W8oGG_NWetux5Gsro3twpykBiyvfCJFNcigjSN4Bcb8Y0Xaz3lgZMzfr8_1p5Ag2BZsNz32L8aEoNn7c3aLpe4B3x7rDK9feua7qqmVoLDHydfwgvqPRxyendfexQUZH-OkJu2wceOQ0UCFveQ4EkpAAgik-XQTViNZQwqvXlG0woPrfdB6fzwBmjxu6aK4 Nov 16 19:22:53 volumiopi volumio[691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 16 19:22:53 volumiopi volumio[691]: info: New Spotify access token = BQD-6ZJ3hVI0DNbzlJ7SGiUcT226bsDpZc49Fbn8XRfr0AH8mxKN_717VLs6W8oGG_NWetux5Gsro3twpykBiyvfCJFNcigjSN4Bcb8Y0Xaz3lgZMzfr8_1p5Ag2BZsNz32L8aEoNn7c3aLpe4B3x7rDK9feua7qqmVoLDHydfwgvqPRxyendfexQUZH-OkJu2wceOQ0UCFveQ4EkpAAgik-XQTViNZQwqvXlG0woPrfdB6fzwBmjxu6aK4 Nov 16 19:22:53 volumiopi volumio[691]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 16 19:22:54 volumiopi volumio[691]: SPOTIFY: User informations: {"country":"PL","display_name":"garfiemiau","email":"garfie@konto.pl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/garfiemiau"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/garfiemiau","id":"garfiemiau","images":[],"product":"premium","type":"user","uri":"spotify:user:garfiemiau"} Nov 16 19:22:54 volumiopi volumio[691]: info: Spotify Successfully logged in Nov 16 19:22:54 volumiopi volumio[691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 16 19:22:54 volumiopi volumio[691]: info: [1731781374085] CoreMusicLibrary::Adding element Spotify Nov 16 19:22:54 volumiopi volumio[691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 16 19:22:54 volumiopi volumio[691]: Cannot find translation for source Spotify Nov 16 19:22:54 volumiopi go-librespot[919]: time="2024-11-16T19:22:54+01:00" level=info msg="generated new device id: c83a2fdeb493c85e67d0308dcf8d542a787dbced" Nov 16 19:22:54 volumiopi go-librespot[919]: time="2024-11-16T19:22:54+01:00" level=debug msg="stored credentials found for garfiemiau" Nov 16 19:22:55 volumiopi go-librespot[919]: time="2024-11-16T19:22:55+01:00" level=debug msg="obtained new client token: AAACq7xUkOh5P1AT6/S3KxKSvIl+hhnpGmdUYH3/e2bz0zz1YqAgyFrtkoaJTKmuMrm9Dh3NF6rnxQTMHpB8XZUo+S9bdCO+f3MGwX4iV6pLbzRdfH/QFXBJMb2LwjyvEut3NCEJoS4fRSTrMBZmcBm5hb6g5Q6E8SHGxnJfRibBEpcVpAYOX9fRUVUnJ9elfV3HgpQkWOm9K1nJJSS9MrotAoDlGasbU04xEvjB6xaVgKyNrcsqIt0FDTEH" Nov 16 19:22:55 volumiopi go-librespot[919]: time="2024-11-16T19:22:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 16 19:22:55 volumiopi go-librespot[919]: time="2024-11-16T19:22:55+01:00" level=debug msg="completed keyexchange" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="completed challenge" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="authenticated as garfiemiau" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="authenticated as garfiemiau" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01: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]" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01: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]" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="dealer connection opened" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="received connection id: MDE0YTNhZDEtZGM2MC00MTgxLWIxNDktNzQxZmJlYzMzYjJmK2RlYWxlcit0Y3A6Ly8wYWNhNDE5Ny5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArM0FBNzAwNjVGNUJFNTE1MEQyOTFCQ0FCM0U4M0U0OEU0QUYwMEI2QTMxNUEwODBEQjQ0OTczNDUzMkI2QkVDNA==" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 16 19:22:56 volumiopi volumio[691]: info: go-librespot daemon successfully initialized Nov 16 19:22:56 volumiopi go-librespot[919]: time="2024-11-16T19:22:56+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 16 19:22:57 volumiopi mpd[909]: Nov 16 19:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 16 19:22:58 volumiopi systemd[1]: Started Music Player Daemon. Nov 16 19:22:58 volumiopi sudo[890]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:58 volumiopi sudo[885]: pam_unix(sudo:session): session closed for user root Nov 16 19:22:58 volumiopi volumio[691]: info: Completed starting Core Plugins Nov 16 19:22:58 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:58 volumiopi volumio[691]: info: ----- MyVolumio plugins startup ---- Nov 16 19:22:58 volumiopi volumio[691]: info: ------------------------------------------- Nov 16 19:22:58 volumiopi volumio[691]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 16 19:22:58 volumiopi volumio[691]: error: MPD error: The expression evaluated to a falsy value: Nov 16 19:22:58 volumiopi volumio[691]: assert.ok(self.idling) Nov 16 19:22:58 volumiopi volumio[691]: error: The expression evaluated to a falsy value: Nov 16 19:22:58 volumiopi volumio[691]: assert.ok(self.idling) Nov 16 19:22:58 volumiopi volumio[691]: info: MPD running with PID909 Nov 16 19:22:58 volumiopi volumio[691]: ,establishing connection Nov 16 19:22:58 volumiopi volumio[691]: error: MPD error: The expression evaluated to a falsy value: Nov 16 19:22:58 volumiopi volumio[691]: assert.ok(self.idling) Nov 16 19:22:58 volumiopi volumio[691]: error: The expression evaluated to a falsy value: Nov 16 19:22:58 volumiopi volumio[691]: assert.ok(self.idling) Nov 16 19:22:58 volumiopi volumio[691]: error: updateQueue error: null Nov 16 19:22:59 volumiopi volumio[691]: info: Initializing connection to go-librespot Websocket Nov 16 19:22:59 volumiopi go-librespot[919]: time="2024-11-16T19:22:59+01:00" level=debug msg="new websocket client" Nov 16 19:22:59 volumiopi volumio[691]: info: Connection to go-librespot Websocket established Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=debug msg="handling transfer player command from 01e5ff8c1d845e47c3bb5ed2a8bfb89b88914b85" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=trace msg="fetched new page 0 with 10 items (list: 10)" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=trace msg="fetched new page 1 with 8 items (list: 18)" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=warning msg="returning empty context page (hm://artistplaycontext/v1/page/spotify/album/1TddwT746HrQCdPemrwgtu/km_artist) for spotify:artist:5ACAhZZPLo1ukYpA4jLO6u" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=error msg="failed fetching next tracks" error="failed moving to next index 18 (page 2): loaded an empty page for 2" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=debug msg="loading track spotify:track:1czCVFnqWvISgMrfJ6W3M6 (paused: false, position: -582815337ms)" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=trace msg="emitting websocket event: will_play" Nov 16 19:23:00 volumiopi volumio[691]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1czCVFnqWvISgMrfJ6W3M6","play_origin":"free-tier-artist"}} Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1czCVFnqWvISgMrfJ6W3M6" Nov 16 19:23:00 volumiopi go-librespot[919]: time="2024-11-16T19:23:00+01:00" level=debug msg="requested aes key for file d96e9e44409cf3bef5522398040c1decbdf9a0dd, gid: 1czCVFnqWvISgMrfJ6W3M6" Nov 16 19:23:00 volumiopi volumio[691]: info: CoreCommandRouter::volumioGetState Nov 16 19:23:00 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:23:00 volumiopi volumio[691]: info: Listing playlists Nov 16 19:23:00 volumiopi volumio[691]: info: Listing playlists Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="fetched first chunk of 40, total size is 20543200 bytes" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=trace msg="seek to -582815337ms (diff: -582815337ms, samples: -25702156361, bytes: 0)" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="fetched chunk 3/39, size: 524288" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=info msg="loaded track \"Caught Up In The Moment\" (uri: spotify:track:1czCVFnqWvISgMrfJ6W3M6, paused: false, position: -582815337ms, duration: 457500ms)" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=trace msg="emitting websocket event: metadata" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=trace msg="emitting websocket event: active" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="sending successful reply for delaer request" Nov 16 19:23:01 volumiopi volumio[691]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1czCVFnqWvISgMrfJ6W3M6","name":"Caught Up In The Moment","artist_names":["Kindrid","Dominique"],"album_name":"Singularity","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e69ecbc4104a37b361b6f8e5","position":-582815337,"duration":457500,"release_date":"year:2020 month:7 day:21","track_number":3,"disc_number":1}} Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 16 19:23:01 volumiopi volumio[691]: SPOTIFY: received: {"type":"active","data":null} Nov 16 19:23:01 volumiopi volumio[691]: info: Aligning Spotify Volume to Volumio Volume Nov 16 19:23:01 volumiopi volumio[691]: info: CoreCommandRouter::volumioGetState Nov 16 19:23:01 volumiopi volumio[691]: info: CorePlayQueue::getTrack 0 Nov 16 19:23:01 volumiopi volumio[691]: info: Setting Spotify Volume from Volumio: 68 Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1342" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=trace msg="emitting websocket event: playing" Nov 16 19:23:01 volumiopi volumio[691]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1czCVFnqWvISgMrfJ6W3M6","play_origin":"free-tier-artist"}} Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="fetched chunk 1/39, size: 524288" Nov 16 19:23:01 volumiopi volumio[691]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="fetched chunk 2/39, size: 524288" Nov 16 19:23:01 volumiopi volumio[691]: TypeError: Cannot read property 'service' of undefined Nov 16 19:23:01 volumiopi volumio[691]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Nov 16 19:23:01 volumiopi volumio[691]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Nov 16 19:23:01 volumiopi volumio[691]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Nov 16 19:23:01 volumiopi volumio[691]: at WebSocket.emit (events.js:315:20) Nov 16 19:23:01 volumiopi volumio[691]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Nov 16 19:23:01 volumiopi volumio[691]: at Receiver.emit (events.js:315:20) Nov 16 19:23:01 volumiopi volumio[691]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Nov 16 19:23:01 volumiopi volumio[691]: at internal/process/task_queues.js:149:7 Nov 16 19:23:01 volumiopi volumio[691]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Nov 16 19:23:01 volumiopi volumio[691]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Nov 16 19:23:01 volumiopi volumio[691]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1116" Nov 16 19:23:01 volumiopi go-librespot[919]: time="2024-11-16T19:23:01+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 16 19:23:02 volumiopi sudo[971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-16 19:22 Nov 16 19:23:02 volumiopi sudo[971]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"