-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sun 2024-12-01 14:35:28 CET. -- Dec 01 14:34:00 volumio-sala systemd[1]: plymouth-start.service: Succeeded. Dec 01 14:34:00 volumio-sala systemd[1]: Started Show Plymouth Boot Screen. Dec 01 14:34:00 volumio-sala systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Dec 01 14:34:00 volumio-sala systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Dec 01 14:34:00 volumio-sala systemd[1]: Reached target Paths. Dec 01 14:34:00 volumio-sala systemd[1]: Reached target Local Encrypted Volumes. Dec 01 14:34:00 volumio-sala systemd-udevd[361]: Using default interface naming scheme 'v240'. Dec 01 14:34:00 volumio-sala kernel: mc: Linux media interface: v0.10 Dec 01 14:34:00 volumio-sala kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:00 volumio-sala kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Dec 01 14:34:00 volumio-sala kernel: [vc_sm_connected_init]: start Dec 01 14:34:00 volumio-sala kernel: [vc_sm_connected_init]: installed successfully Dec 01 14:34:00 volumio-sala systemd-udevd[361]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Dec 01 14:34:00 volumio-sala kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Dec 01 14:34:00 volumio-sala kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Dec 01 14:34:00 volumio-sala kernel: videodev: Linux video capture interface: v2.00 Dec 01 14:34:01 volumio-sala kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:01 volumio-sala kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Dec 01 14:34:01 volumio-sala kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:01 volumio-sala systemd[1]: Found device /dev/disk/by-uuid/41CA-9A8B. Dec 01 14:34:01 volumio-sala kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:01 volumio-sala kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:01 volumio-sala kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:01 volumio-sala kernel: rpivid feb10000.codec: Device registered as /dev/video19 Dec 01 14:34:01 volumio-sala kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Dec 01 14:34:01 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Dec 01 14:34:01 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Dec 01 14:34:01 volumio-sala kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 14:34:01 volumio-sala kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Dec 01 14:34:01 volumio-sala kernel: Bluetooth: Core ver 2.22 Dec 01 14:34:01 volumio-sala kernel: NET: Registered PF_BLUETOOTH protocol family Dec 01 14:34:01 volumio-sala kernel: Bluetooth: HCI device and connection manager initialized Dec 01 14:34:01 volumio-sala kernel: Bluetooth: HCI socket layer initialized Dec 01 14:34:01 volumio-sala kernel: Bluetooth: L2CAP socket layer initialized Dec 01 14:34:01 volumio-sala kernel: Bluetooth: SCO socket layer initialized Dec 01 14:34:01 volumio-sala systemd-udevd[374]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Dec 01 14:34:01 volumio-sala kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Dec 01 14:34:01 volumio-sala kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Dec 01 14:34:01 volumio-sala kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Dec 01 14:34:01 volumio-sala kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Dec 01 14:34:01 volumio-sala kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Dec 01 14:34:02 volumio-sala kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Dec 01 14:34:02 volumio-sala kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Dec 01 14:34:02 volumio-sala kernel: Bluetooth: HCI UART driver ver 2.3 Dec 01 14:34:02 volumio-sala kernel: Bluetooth: HCI UART protocol H4 registered Dec 01 14:34:02 volumio-sala kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Dec 01 14:34:02 volumio-sala kernel: Bluetooth: HCI UART protocol Broadcom registered Dec 01 14:34:02 volumio-sala kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Dec 01 14:34:02 volumio-sala kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Dec 01 14:34:02 volumio-sala kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Dec 01 14:34:02 volumio-sala kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Dec 01 14:34:02 volumio-sala kernel: usbcore: registered new interface driver brcmfmac Dec 01 14:34:02 volumio-sala kernel: uart-pl011 fe201000.serial: no DMA platform data Dec 01 14:34:02 volumio-sala systemd-udevd[401]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Dec 01 14:34:02 volumio-sala systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Dec 01 14:34:02 volumio-sala kernel: Bluetooth: hci0: BCM: chip id 107 Dec 01 14:34:02 volumio-sala kernel: Bluetooth: hci0: BCM: features 0x2f Dec 01 14:34:02 volumio-sala kernel: Bluetooth: hci0: BCM4345C0 Dec 01 14:34:02 volumio-sala kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Dec 01 14:34:02 volumio-sala kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Dec 01 14:34:02 volumio-sala kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Dec 01 14:34:02 volumio-sala kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Dec 01 14:34:03 volumio-sala systemd-udevd[379]: Using default interface naming scheme 'v240'. Dec 01 14:34:03 volumio-sala systemd-udevd[379]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Dec 01 14:34:03 volumio-sala kernel: usbcore: registered new interface driver snd-usb-audio Dec 01 14:34:03 volumio-sala kernel: alsactl[492]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Dec 01 14:34:03 volumio-sala kernel: Bluetooth: hci0: BCM: features 0x2f Dec 01 14:34:03 volumio-sala kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Dec 01 14:34:03 volumio-sala kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Dec 01 14:34:03 volumio-sala systemd[1]: Created slice system-bthelper.slice. Dec 01 14:34:03 volumio-sala systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Dec 01 14:34:03 volumio-sala systemd[1]: Condition check resulted in Huge Pages File System being skipped. Dec 01 14:34:03 volumio-sala systemd[1]: Starting Show Plymouth Boot Screen... Dec 01 14:34:03 volumio-sala systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Dec 01 14:34:03 volumio-sala systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Dec 01 14:34:03 volumio-sala systemd[1]: Starting File System Check on /dev/disk/by-uuid/41CA-9A8B... Dec 01 14:34:03 volumio-sala systemd[1]: Starting Load/Save RF Kill Switch Status... Dec 01 14:34:04 volumio-sala systemd[1]: plymouth-start.service: Succeeded. Dec 01 14:34:04 volumio-sala systemd[1]: Started Show Plymouth Boot Screen. Dec 01 14:34:04 volumio-sala systemd[1]: Started File System Check Daemon to report status. Dec 01 14:34:04 volumio-sala systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Dec 01 14:34:04 volumio-sala systemd[1]: Started Load/Save RF Kill Switch Status. Dec 01 14:34:04 volumio-sala systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Dec 01 14:34:04 volumio-sala systemd-udevd[400]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Dec 01 14:34:04 volumio-sala systemd-fsck[511]: fsck.fat 4.1 (2017-01-24) Dec 01 14:34:04 volumio-sala systemd-fsck[511]: /dev/mmcblk0p1: 402 files, 166094/184582 clusters Dec 01 14:34:04 volumio-sala systemd[1]: Started File System Check on /dev/disk/by-uuid/41CA-9A8B. Dec 01 14:34:04 volumio-sala systemd[1]: Mounting /boot... Dec 01 14:34:04 volumio-sala systemd[1]: Mounted /boot. Dec 01 14:34:04 volumio-sala systemd[1]: Reached target Local File Systems. Dec 01 14:34:04 volumio-sala systemd[1]: Starting Raise network interfaces... Dec 01 14:34:04 volumio-sala systemd[1]: Starting Preprocess NFS configuration... Dec 01 14:34:04 volumio-sala systemd[1]: Started ifup for wlan0. Dec 01 14:34:04 volumio-sala systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Dec 01 14:34:04 volumio-sala systemd[1]: Started ifup for eth0. Dec 01 14:34:04 volumio-sala systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Dec 01 14:34:04 volumio-sala systemd[1]: Starting Create Volatile Files and Directories... Dec 01 14:34:04 volumio-sala systemd[1]: Received SIGRTMIN+20 from PID 205 (plymouthd). Dec 01 14:34:04 volumio-sala systemd[1]: nfs-config.service: Succeeded. Dec 01 14:34:04 volumio-sala systemd[1]: Started Preprocess NFS configuration. Dec 01 14:34:04 volumio-sala systemd[1]: plymouth-read-write.service: Succeeded. Dec 01 14:34:04 volumio-sala systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Dec 01 14:34:04 volumio-sala systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Dec 01 14:34:04 volumio-sala systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Dec 01 14:34:04 volumio-sala systemd[1]: Reached target NFS client services. Dec 01 14:34:04 volumio-sala kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Dec 01 14:34:04 volumio-sala systemd[1]: Started Create Volatile Files and Directories. Dec 01 14:34:04 volumio-sala systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Dec 01 14:34:04 volumio-sala systemd[1]: Starting RPC bind portmap service... Dec 01 14:34:04 volumio-sala systemd[1]: Starting Update UTMP about System Boot/Shutdown... Dec 01 14:34:05 volumio-sala systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Dec 01 14:34:05 volumio-sala kernel: 8021q: 802.1Q VLAN Support v1.8 Dec 01 14:34:05 volumio-sala kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 01 14:34:05 volumio-sala systemd[1]: Started Update UTMP about System Boot/Shutdown. Dec 01 14:34:05 volumio-sala systemd[1]: Started RPC bind portmap service. Dec 01 14:34:05 volumio-sala systemd[1]: Reached target Remote File Systems (Pre). Dec 01 14:34:05 volumio-sala systemd[1]: Reached target Remote File Systems. Dec 01 14:34:05 volumio-sala systemd[1]: Reached target RPC Port Mapper. Dec 01 14:34:05 volumio-sala systemd[1]: Reached target System Initialization. Dec 01 14:34:05 volumio-sala systemd[1]: Listening on D-Bus System Message Bus Socket. Dec 01 14:34:05 volumio-sala systemd[1]: Listening on triggerhappy.socket. Dec 01 14:34:05 volumio-sala systemd[1]: Started Daily apt download activities. Dec 01 14:34:05 volumio-sala systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Dec 01 14:34:05 volumio-sala systemd[1]: Reached target Sockets. Dec 01 14:34:05 volumio-sala systemd[1]: Started Daily apt upgrade and clean activities. Dec 01 14:34:05 volumio-sala systemd[1]: Reached target Basic System. Dec 01 14:34:05 volumio-sala systemd[1]: Starting Volumio Time Update Utility... Dec 01 14:34:05 volumio-sala systemd[1]: Started Volumio Log Rotation Service. Dec 01 14:34:05 volumio-sala systemd[1]: Starting triggerhappy global hotkey daemon... Dec 01 14:34:05 volumio-sala systemd[1]: Starting Wireless Services... Dec 01 14:34:05 volumio-sala systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Dec 01 14:34:05 volumio-sala volumio-time-update[609]: volumio-time-update-util: Fetching time from Volumio... Dec 01 14:34:05 volumio-sala systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Dec 01 14:34:05 volumio-sala systemd[1]: Started volumio-remote-updater.service. Dec 01 14:34:05 volumio-sala systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Dec 01 14:34:05 volumio-sala thd[625]: Unable to parse trigger line: Dec 01 14:34:05 volumio-sala thd[625]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Dec 01 14:34:05 volumio-sala thd[625]: Unable to parse trigger line: Dec 01 14:34:05 volumio-sala thd[625]: Found socket passed from systemd Dec 01 14:34:05 volumio-sala systemd[1]: Starting Configure Bluetooth Modems connected by UART... Dec 01 14:34:05 volumio-sala systemd[1]: Starting Login Service... Dec 01 14:34:05 volumio-sala systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Dec 01 14:34:05 volumio-sala systemd[1]: Started Volumio Iptables Module. Dec 01 14:34:05 volumio-sala systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Dec 01 14:34:05 volumio-sala systemd[1]: Started UPnP Renderer front-end to MPD. Dec 01 14:34:05 volumio-sala systemd[1]: Started Manage Sound Card State (restore and store). Dec 01 14:34:05 volumio-sala alsactl[653]: alsactl 1.1.8 daemon started Dec 01 14:34:05 volumio-sala systemd[1]: Starting Save/Restore Sound Card State... Dec 01 14:34:05 volumio-sala systemd[1]: Started MPD Monitor Service. Dec 01 14:34:05 volumio-sala systemd[1]: Started D-Bus System Message Bus. Dec 01 14:34:05 volumio-sala sh[530]: eth0: waiting for carrier Dec 01 14:34:05 volumio-sala dhcpcd[572]: eth0: waiting for carrier Dec 01 14:34:05 volumio-sala kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Dec 01 14:34:05 volumio-sala kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 01 14:34:05 volumio-sala systemd[1]: Starting WPA supplicant... Dec 01 14:34:05 volumio-sala systemd[1]: Starting dhcpcd on all interfaces... Dec 01 14:34:05 volumio-sala systemd[1]: Started Daily Cleanup of Temporary Directories. Dec 01 14:34:05 volumio-sala systemd[1]: Started Daily man-db regeneration. Dec 01 14:34:05 volumio-sala systemd[1]: Reached target Timers. Dec 01 14:34:05 volumio-sala systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Dec 01 14:34:05 volumio-sala systemd[1]: Started triggerhappy global hotkey daemon. Dec 01 14:34:05 volumio-sala systemd[1]: hciuart.service: Succeeded. Dec 01 14:34:05 volumio-sala systemd-logind[646]: New seat seat0. Dec 01 14:34:05 volumio-sala systemd[1]: Started Configure Bluetooth Modems connected by UART. Dec 01 14:34:05 volumio-sala systemd[1]: Started Save/Restore Sound Card State. Dec 01 14:34:06 volumio-sala dhcpcd[666]: Not running dhcpcd because /etc/network/interfaces Dec 01 14:34:06 volumio-sala dhcpcd[666]: defines some interfaces that will use a Dec 01 14:34:06 volumio-sala dhcpcd[666]: DHCP client or static address Dec 01 14:34:06 volumio-sala systemd[1]: Reached target Sound Card. Dec 01 14:34:06 volumio-sala systemd[1]: Starting Raspberry Pi bluetooth helper... Dec 01 14:34:06 volumio-sala systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Dec 01 14:34:06 volumio-sala systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Dec 01 14:34:06 volumio-sala avahi-daemon[636]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Dec 01 14:34:06 volumio-sala systemd[1]: Failed to start dhcpcd on all interfaces. Dec 01 14:34:06 volumio-sala avahi-daemon[636]: Successfully dropped root privileges. Dec 01 14:34:06 volumio-sala avahi-daemon[636]: avahi-daemon 0.7 starting up. Dec 01 14:34:06 volumio-sala mpd_monitor.sh[659]: MPD error: Connection refused Dec 01 14:34:06 volumio-sala mpd_monitor.sh[659]: mpd: no process found Dec 01 14:34:06 volumio-sala volumio-remote-updater[640]: Error: No active session Dec 01 14:34:06 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:06] [info] asio async_connect error: system:111 (Connection refused) Dec 01 14:34:06 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:06] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 01 14:34:06 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:06] [error] handle_connect error: Underlying Transport Error Dec 01 14:34:06 volumio-sala sh[528]: wlan0=wlan0 Dec 01 14:34:06 volumio-sala volumio-time-update[609]: volumio-time-update-util: Date not found in response Dec 01 14:34:06 volumio-sala volumio-time-update[609]: volumio-time-update-util: Retrying in 5 seconds... Dec 01 14:34:06 volumio-sala bthelper[681]: Raspberry Pi BDADDR already set Dec 01 14:34:06 volumio-sala systemd[1]: Started Raspberry Pi bluetooth helper. Dec 01 14:34:06 volumio-sala systemd[1]: Starting Bluetooth service... Dec 01 14:34:06 volumio-sala systemd[1]: Listening on mpd.socket. Dec 01 14:34:06 volumio-sala wpa_supplicant[665]: Successfully initialized wpa_supplicant Dec 01 14:34:07 volumio-sala systemd[1]: Started Raise network interfaces. Dec 01 14:34:07 volumio-sala avahi-daemon[636]: Successfully called chroot(). Dec 01 14:34:07 volumio-sala avahi-daemon[636]: Successfully dropped remaining capabilities. Dec 01 14:34:07 volumio-sala dbus-daemon[664]: [system] Successfully activated service 'org.freedesktop.systemd1' Dec 01 14:34:07 volumio-sala systemd[1]: Started Login Service. Dec 01 14:34:07 volumio-sala avahi-daemon[636]: Loading service file /services/volumio.service. Dec 01 14:34:07 volumio-sala systemd[1]: Started Avahi mDNS/DNS-SD Stack. Dec 01 14:34:07 volumio-sala systemd[1]: Started WPA supplicant. Dec 01 14:34:07 volumio-sala systemd[1]: Reached target Network. Dec 01 14:34:07 volumio-sala avahi-daemon[636]: Network interface enumeration completed. Dec 01 14:34:07 volumio-sala avahi-daemon[636]: Server startup complete. Host name is volumio-sala.local. Local service cookie is 3878264829. Dec 01 14:34:07 volumio-sala systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Dec 01 14:34:07 volumio-sala avahi-daemon[636]: Service "Volumio Sala" (/services/volumio.service) successfully established. Dec 01 14:34:07 volumio-sala systemd[1]: Starting Permit User Sessions... Dec 01 14:34:07 volumio-sala systemd[1]: Starting Music Player Daemon... Dec 01 14:34:07 volumio-sala systemd[1]: Starting OpenBSD Secure Shell server... Dec 01 14:34:07 volumio-sala systemd[1]: Reached target Network is Online. Dec 01 14:34:07 volumio-sala systemd[1]: Starting /etc/rc.local Compatibility... Dec 01 14:34:07 volumio-sala systemd[1]: Starting LSB: Brings up/down network automatically... Dec 01 14:34:07 volumio-sala systemd[1]: Starting Samba NMB Daemon... Dec 01 14:34:07 volumio-sala systemd[1]: Starting Network Time Service... Dec 01 14:34:07 volumio-sala systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 01 14:34:07 volumio-sala loadcpufreq[647]: Loading cpufreq kernel modules...done (none). Dec 01 14:34:07 volumio-sala systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Dec 01 14:34:07 volumio-sala systemd[1]: Started Permit User Sessions. Dec 01 14:34:07 volumio-sala systemd[1]: Started /etc/rc.local Compatibility. Dec 01 14:34:07 volumio-sala volumio[652]: Could not open config: /tmp/upmpdcli.conf Dec 01 14:34:07 volumio-sala systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 01 14:34:07 volumio-sala systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 01 14:34:07 volumio-sala bluetoothd[732]: Bluetooth daemon 5.50 Dec 01 14:34:07 volumio-sala bluetoothd[732]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Dec 01 14:34:07 volumio-sala systemd[1]: Started Bluetooth service. Dec 01 14:34:07 volumio-sala systemd[1]: Reached target Bluetooth. Dec 01 14:34:07 volumio-sala bluetoothd[732]: Starting SDP server Dec 01 14:34:07 volumio-sala bluetoothd[732]: Excluding (cli) sap Dec 01 14:34:07 volumio-sala systemd[1]: Starting Terminate Plymouth Boot Screen... Dec 01 14:34:07 volumio-sala systemd[1]: Starting Hold until boot process finishes up... Dec 01 14:34:07 volumio-sala systemd[1]: Starting LSB: set CPUFreq kernel parameters... Dec 01 14:34:08 volumio-sala systemd[1]: Received SIGRTMIN+21 from PID 205 (plymouthd). Dec 01 14:34:08 volumio-sala systemd[1]: Received SIGRTMIN+21 from PID 205 (plymouthd). Dec 01 14:34:08 volumio-sala systemd[1]: plymouth-quit.service: Succeeded. Dec 01 14:34:08 volumio-sala sshd[786]: Server listening on 0.0.0.0 port 22. Dec 01 14:34:08 volumio-sala sshd[786]: Server listening on :: port 22. Dec 01 14:34:08 volumio-sala systemd[1]: Started Terminate Plymouth Boot Screen. Dec 01 14:34:08 volumio-sala systemd[1]: plymouth-quit-wait.service: Succeeded. Dec 01 14:34:08 volumio-sala systemd[1]: Started Hold until boot process finishes up. Dec 01 14:34:08 volumio-sala systemd[1]: Started OpenBSD Secure Shell server. Dec 01 14:34:08 volumio-sala kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Dec 01 14:34:08 volumio-sala kernel: Bluetooth: BNEP filters: protocol multicast Dec 01 14:34:08 volumio-sala kernel: Bluetooth: BNEP socket layer initialized Dec 01 14:34:08 volumio-sala systemd[1]: Started Getty on tty1. Dec 01 14:34:08 volumio-sala systemd[1]: Reached target Login Prompts. Dec 01 14:34:08 volumio-sala bluetoothd[732]: Bluetooth management interface 1.22 initialized Dec 01 14:34:08 volumio-sala ifplugd(eth0)[800]: ifplugd 0.28 initializing. Dec 01 14:34:08 volumio-sala dbus-daemon[664]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=732 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Dec 01 14:34:08 volumio-sala kernel: Bluetooth: MGMT ver 1.22 Dec 01 14:34:08 volumio-sala ifplugd(eth0)[800]: Using interface eth0/E4:5F:01:18:FD:BE with driver (version: 6.6.56-v7l+) Dec 01 14:34:08 volumio-sala ifplugd(eth0)[800]: Using detection mode: SIOCETHTOOL Dec 01 14:34:08 volumio-sala ifplugd(eth0)[800]: Initialization complete, link beat not detected. Dec 01 14:34:08 volumio-sala bluetoothd[732]: Failed to set privacy: Rejected (0x0b) Dec 01 14:34:08 volumio-sala ntpd[768]: ntpd 4.2.8p12@1.3728-o (1): Starting Dec 01 14:34:08 volumio-sala ntpd[768]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Dec 01 14:34:08 volumio-sala ifplugd[759]: Network Interface Plugging Daemon...start eth0...done. Dec 01 14:34:08 volumio-sala ntpd[802]: proto: precision = 3.093 usec (-18) Dec 01 14:34:08 volumio-sala ntpd[802]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Dec 01 14:34:08 volumio-sala ntpd[802]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Dec 01 14:34:08 volumio-sala ntpd[802]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): will expire in less than 27 days Dec 01 14:34:08 volumio-sala ntpd[802]: Listen and drop on 0 v6wildcard [::]:123 Dec 01 14:34:08 volumio-sala ntpd[802]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Dec 01 14:34:08 volumio-sala ntpd[802]: Listen normally on 2 lo 127.0.0.1:123 Dec 01 14:34:08 volumio-sala ntpd[802]: Listening on routing socket on fd #19 for interface updates Dec 01 14:34:08 volumio-sala ntpd[802]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 01 14:34:08 volumio-sala ntpd[802]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 01 14:34:08 volumio-sala systemd[1]: Started LSB: Brings up/down network automatically. Dec 01 14:34:08 volumio-sala systemd[1]: Started Network Time Service. Dec 01 14:34:08 volumio-sala systemd[1]: iptables.service: Succeeded. Dec 01 14:34:08 volumio-sala sudo[748]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 01 14:34:08 volumio-sala sudo[748]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:09 volumio-sala systemd[1]: Starting Hostname Service... Dec 01 14:34:09 volumio-sala sudo[748]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 01 14:34:09 volumio-sala sudo[748]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:09 volumio-sala systemd[1]: systemd-rfkill.service: Succeeded. Dec 01 14:34:09 volumio-sala cpufrequtils[784]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Dec 01 14:34:09 volumio-sala systemd[1]: Started LSB: set CPUFreq kernel parameters. Dec 01 14:34:09 volumio-sala dbus-daemon[664]: [system] Successfully activated service 'org.freedesktop.hostname1' Dec 01 14:34:09 volumio-sala systemd[1]: Started Hostname Service. Dec 01 14:34:09 volumio-sala ntpd[802]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Dec 01 14:34:09 volumio-sala haveged[595]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Dec 01 14:34:09 volumio-sala haveged[595]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Dec 01 14:34:09 volumio-sala haveged[595]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99643 Dec 01 14:34:09 volumio-sala haveged[595]: haveged: fills: 0, generated: 0 Dec 01 14:34:10 volumio-sala nmbd[775]: [2024/12/01 14:34:10.281313, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Dec 01 14:34:10 volumio-sala nmbd[775]: started asyncdns process 824 Dec 01 14:34:10 volumio-sala nmbd[775]: [2024/12/01 14:34:10.283870, 0] ../lib/util/become_daemon.c:149(daemon_status) Dec 01 14:34:10 volumio-sala nmbd[775]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Dec 01 14:34:10 volumio-sala nmbd[775]: [2024/12/01 14:34:10.284024, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Dec 01 14:34:10 volumio-sala nmbd[775]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Dec 01 14:34:10 volumio-sala ntpd[802]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Dec 01 14:34:10 volumio-sala wireless.js[629]: Cleaning previous... Dec 01 14:34:10 volumio-sala kernel: new mount options do not match the existing superblock, will be ignored Dec 01 14:34:10 volumio-sala sudo[834]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Dec 01 14:34:10 volumio-sala sudo[834]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:10 volumio-sala sudo[834]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:10 volumio-sala sudo[838]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Dec 01 14:34:10 volumio-sala sudo[838]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:11 volumio-sala volumio[651]: cset: --> shielding system active with Dec 01 14:34:11 volumio-sala volumio[651]: cset: "system" cpuset of CPUSPEC(0-1) with 78 tasks running Dec 01 14:34:11 volumio-sala volumio[651]: cset: "user" cpuset of CPUSPEC(2-3) with 1 task running Dec 01 14:34:11 volumio-sala systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Dec 01 14:34:11 volumio-sala sudo[838]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:11 volumio-sala ntpd[802]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Dec 01 14:34:11 volumio-sala wireless.js[629]: Stopped aP Dec 01 14:34:11 volumio-sala sudo[855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 01 14:34:11 volumio-sala sudo[855]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:11 volumio-sala kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 01 14:34:11 volumio-sala sudo[855]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:11 volumio-sala sudo[857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 01 14:34:11 volumio-sala sudo[857]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:11 volumio-sala sudo[857]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:11 volumio-sala sudo[864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 01 14:34:11 volumio-sala sudo[864]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:11 volumio-sala sudo[864]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:11 volumio-sala sudo[866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 01 14:34:11 volumio-sala sudo[866]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:11 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:11] [info] asio async_connect error: system:111 (Connection refused) Dec 01 14:34:11 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 01 14:34:11 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:11] [error] handle_connect error: Underlying Transport Error Dec 01 14:34:11 volumio-sala volumio-time-update[609]: volumio-time-update-util: Fetching time from Volumio... Dec 01 14:34:11 volumio-sala volumio-time-update[609]: volumio-time-update-util: Date not found in response Dec 01 14:34:11 volumio-sala volumio-time-update[609]: volumio-time-update-util: Retrying in 5 seconds... Dec 01 14:34:11 volumio-sala bthelper[681]: Changing power off succeeded Dec 01 14:34:12 volumio-sala bthelper[681]: [CHG] Controller E4:5F:01:18:FD:C0 Class: 0x0000041c Dec 01 14:34:12 volumio-sala bthelper[681]: Changing power on succeeded Dec 01 14:34:12 volumio-sala mpd[819]: Dec 01 14:34 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 01 14:34:12 volumio-sala ntpd[802]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Dec 01 14:34:12 volumio-sala systemd[1]: Started Music Player Daemon. Dec 01 14:34:12 volumio-sala mpd_monitor.sh[659]: MPD restarted due to no mpc output. Dec 01 14:34:14 volumio-sala sudo[866]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:14 volumio-sala wireless.js[629]: SETTING APPROPRIATE REG DOMAIN: IT Dec 01 14:34:14 volumio-sala sudo[887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 01 14:34:14 volumio-sala sudo[887]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:14 volumio-sala sudo[887]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:14 volumio-sala sudo[889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set IT Dec 01 14:34:14 volumio-sala sudo[889]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:14 volumio-sala sudo[889]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:14 volumio-sala wireless.js[629]: SUCCESSFULLY SET NEW REGDOMAIN: IT Dec 01 14:34:14 volumio-sala wireless.js[629]: Start wireless flow Dec 01 14:34:14 volumio-sala wireless.js[629]: Stopped hotspot (if there).. Dec 01 14:34:14 volumio-sala sudo[894]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Dec 01 14:34:14 volumio-sala sudo[894]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:14 volumio-sala sudo[894]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:14 volumio-sala sudo[896]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Dec 01 14:34:14 volumio-sala sudo[896]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:14 volumio-sala sudo[896]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:14 volumio-sala wireless.js[629]: DHCP IP Dec 01 14:34:14 volumio-sala wpa_supplicant[898]: Successfully initialized wpa_supplicant Dec 01 14:34:14 volumio-sala wireless.js[629]: Start ap Dec 01 14:34:14 volumio-sala sudo[899]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 01 14:34:14 volumio-sala sudo[899]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:14 volumio-sala kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 01 14:34:14 volumio-sala dhcpcd[900]: dev: loaded udev Dec 01 14:34:15 volumio-sala dhcpcd-run-hooks[918]: wlan0: starting wpa_supplicant Dec 01 14:34:15 volumio-sala dhcpcd-run-hooks[923]: wlan0: failed to start wpa_supplicant Dec 01 14:34:15 volumio-sala dhcpcd-run-hooks[924]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Dec 01 14:34:15 volumio-sala dhcpcd[900]: wlan0: connected to Access Point `' Dec 01 14:34:15 volumio-sala dhcpcd[900]: no interfaces have a carrier Dec 01 14:34:15 volumio-sala dhcpcd[900]: forked to background, child pid 934 Dec 01 14:34:15 volumio-sala dhcpcd[934]: eth0: waiting for carrier Dec 01 14:34:15 volumio-sala dhcpcd[934]: wlan0: waiting for carrier Dec 01 14:34:15 volumio-sala sudo[899]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:15 volumio-sala wireless.js[629]: trying... Dec 01 14:34:15 volumio-sala sudo[936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:15 volumio-sala sudo[936]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:15 volumio-sala sudo[936]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:16 volumio-sala volumio-time-update[609]: volumio-time-update-util: Fetching time from Volumio... Dec 01 14:34:16 volumio-sala volumio-time-update[609]: volumio-time-update-util: Date not found in response Dec 01 14:34:16 volumio-sala volumio-time-update[609]: volumio-time-update-util: Retrying in 5 seconds... Dec 01 14:34:16 volumio-sala wireless.js[629]: trying... Dec 01 14:34:16 volumio-sala sudo[944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:16 volumio-sala sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:16 volumio-sala sudo[944]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:17 volumio-sala wireless.js[629]: trying... Dec 01 14:34:17 volumio-sala sudo[947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:17 volumio-sala sudo[947]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:17 volumio-sala sudo[947]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:18 volumio-sala wireless.js[629]: trying... Dec 01 14:34:18 volumio-sala sudo[950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:18 volumio-sala sudo[950]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:18 volumio-sala sudo[950]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:19 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:19] [info] asio async_connect error: system:111 (Connection refused) Dec 01 14:34:19 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:19] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 01 14:34:19 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:19] [error] handle_connect error: Underlying Transport Error Dec 01 14:34:19 volumio-sala wireless.js[629]: trying... Dec 01 14:34:19 volumio-sala sudo[953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:19 volumio-sala sudo[953]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:19 volumio-sala sudo[953]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:20 volumio-sala wireless.js[629]: trying... Dec 01 14:34:20 volumio-sala sudo[956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:20 volumio-sala sudo[956]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:20 volumio-sala sudo[956]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:21 volumio-sala wpa_supplicant[922]: wlan0: Trying to associate with SSID 'Vodafone-C01570129' Dec 01 14:34:21 volumio-sala wpa_supplicant[922]: wlan0: Associated with 80:16:05:ea:3c:1c Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: carrier acquired Dec 01 14:34:21 volumio-sala wpa_supplicant[922]: wlan0: CTRL-EVENT-CONNECTED - Connection to 80:16:05:ea:3c:1c completed [id=0 id_str=] Dec 01 14:34:21 volumio-sala wpa_supplicant[922]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 01 14:34:21 volumio-sala wpa_supplicant[922]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=IT Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: connected to Access Point `Vodafone-C01570129' Dec 01 14:34:21 volumio-sala dhcpcd[934]: DUID 00:01:00:01:2e:31:56:e1:e4:5f:01:18:fd:bf Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: IAID 01:18:fd:bf Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: adding address fe80::5cde:78c5:3b5d:d9ef Dec 01 14:34:21 volumio-sala dhcpcd[934]: ipv6_addaddr1: Permission denied Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: carrier lost Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: carrier acquired Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: IAID 01:18:fd:bf Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: soliciting a DHCP lease Dec 01 14:34:21 volumio-sala dhcpcd[934]: wlan0: soliciting an IPv6 router Dec 01 14:34:21 volumio-sala volumio-time-update[609]: volumio-time-update-util: Fetching time from Volumio... Dec 01 14:34:21 volumio-sala volumio-time-update[609]: volumio-time-update-util: Date not found in response Dec 01 14:34:21 volumio-sala volumio-time-update[609]: volumio-time-update-util: Retrying in 5 seconds... Dec 01 14:34:21 volumio-sala wireless.js[629]: trying... Dec 01 14:34:21 volumio-sala sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:21 volumio-sala sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:21 volumio-sala sudo[976]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:22 volumio-sala wireless.js[629]: trying... Dec 01 14:34:22 volumio-sala sudo[982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:22 volumio-sala sudo[982]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:22 volumio-sala sudo[982]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:23 volumio-sala wireless.js[629]: trying... Dec 01 14:34:23 volumio-sala sudo[985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:23 volumio-sala sudo[985]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:23 volumio-sala sudo[985]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:24 volumio-sala wireless.js[629]: trying... Dec 01 14:34:24 volumio-sala sudo[988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:24 volumio-sala sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:24 volumio-sala sudo[988]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:25 volumio-sala dhcpcd[934]: wlan0: offered 192.168.1.12 from 192.168.1.1 Dec 01 14:34:25 volumio-sala dhcpcd[934]: wlan0: probing address 192.168.1.12/24 Dec 01 14:34:25 volumio-sala wireless.js[629]: trying... Dec 01 14:34:25 volumio-sala sudo[991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:25 volumio-sala sudo[991]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:25 volumio-sala sudo[991]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:26 volumio-sala volumio-time-update[609]: volumio-time-update-util: Fetching time from Volumio... Dec 01 14:34:26 volumio-sala volumio-time-update[609]: volumio-time-update-util: Date not found in response Dec 01 14:34:26 volumio-sala volumio-time-update[609]: volumio-time-update-util: Retrying in 5 seconds... Dec 01 14:34:26 volumio-sala wireless.js[629]: trying... Dec 01 14:34:26 volumio-sala sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:26 volumio-sala sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:26 volumio-sala sudo[999]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:27 volumio-sala wireless.js[629]: trying... Dec 01 14:34:27 volumio-sala sudo[1002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:27 volumio-sala sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:27 volumio-sala sudo[1002]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:28 volumio-sala wireless.js[629]: trying... Dec 01 14:34:28 volumio-sala sudo[1005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:28 volumio-sala sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:28 volumio-sala sudo[1005]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:29 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:29] [info] asio async_connect error: system:111 (Connection refused) Dec 01 14:34:29 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:29] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 01 14:34:29 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:34:29] [error] handle_connect error: Underlying Transport Error Dec 01 14:34:29 volumio-sala wireless.js[629]: trying... Dec 01 14:34:29 volumio-sala sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:29 volumio-sala sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:29 volumio-sala sudo[1008]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:30 volumio-sala dhcpcd[934]: wlan0: leased 192.168.1.12 for 86400 seconds Dec 01 14:34:30 volumio-sala avahi-daemon[636]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.12. Dec 01 14:34:30 volumio-sala dhcpcd[934]: wlan0: adding route to 192.168.1.0/24 Dec 01 14:34:30 volumio-sala avahi-daemon[636]: New relevant interface wlan0.IPv4 for mDNS. Dec 01 14:34:30 volumio-sala dhcpcd[934]: wlan0: adding default route via 192.168.1.1 Dec 01 14:34:30 volumio-sala avahi-daemon[636]: Registering new address record for 192.168.1.12 on wlan0.IPv4. Dec 01 14:34:30 volumio-sala wireless.js[629]: trying... Dec 01 14:34:30 volumio-sala sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 01 14:34:30 volumio-sala sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:30 volumio-sala sudo[1033]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:30 volumio-sala wireless.js[629]: Connected to: ----Vodafone-C01570129 Dec 01 14:34:30 volumio-sala wireless.js[629]: ---- Dec 01 14:34:30 volumio-sala sudo[1041]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 14:34:30 volumio-sala sudo[1041]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:30 volumio-sala sudo[1041]: pam_unix(sudo:session): session closed for user root Dec 01 14:34:31 volumio-sala wireless.js[629]: ... joined AP, wlan0 IPv4 is 192.168.1.12, ipV6 is undefined Dec 01 14:34:31 volumio-sala wireless.js[629]: It's done! AP Dec 01 14:34:31 volumio-sala ntpd[802]: ntpd exiting on signal 15 (Terminated) Dec 01 14:34:31 volumio-sala systemd[1]: Stopping Network Time Service... Dec 01 14:34:31 volumio-sala systemd[1]: ntp.service: Succeeded. Dec 01 14:34:31 volumio-sala systemd[1]: Stopped Network Time Service. Dec 01 14:34:31 volumio-sala systemd[1]: Starting Network Time Service... Dec 01 14:34:31 volumio-sala systemd[1]: Started Wireless Services. Dec 01 14:34:31 volumio-sala kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 01 14:34:31 volumio-sala systemd[1]: Started Volumio Backend Module. Dec 01 14:34:31 volumio-sala ntpd[1048]: ntpd 4.2.8p12@1.3728-o (1): Starting Dec 01 14:34:31 volumio-sala ntpd[1048]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 103:103 Dec 01 14:34:31 volumio-sala systemd[1]: Started Volumio Cpu Tweaker. Dec 01 14:34:31 volumio-sala ntpd[1061]: proto: precision = 1.185 usec (-20) Dec 01 14:34:31 volumio-sala systemd[1]: Started Network Time Service. Dec 01 14:34:31 volumio-sala ntpd[1061]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Dec 01 14:34:31 volumio-sala ntpd[1061]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Dec 01 14:34:31 volumio-sala ntpd[1061]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): will expire in less than 27 days Dec 01 14:34:31 volumio-sala ntpd[1061]: Listen and drop on 0 v6wildcard [::]:123 Dec 01 14:34:31 volumio-sala ntpd[1061]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Dec 01 14:34:31 volumio-sala ntpd[1061]: Listen normally on 2 lo 127.0.0.1:123 Dec 01 14:34:31 volumio-sala ntpd[1061]: Listen normally on 3 wlan0 192.168.1.12:123 Dec 01 14:34:31 volumio-sala ntpd[1061]: Listening on routing socket on fd #20 for interface updates Dec 01 14:34:31 volumio-sala ntpd[1061]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 01 14:34:31 volumio-sala ntpd[1061]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 01 14:34:31 volumio-sala volumio-cpu-tweak[1060]: Setting RT Priority for mpd Dec 01 14:34:31 volumio-sala volumio-cpu-tweak[1060]: Setting MPD Affinity Dec 01 14:34:31 volumio-sala volumio-cpu-tweak[1060]: taskset: failed to set pid 819's affinity: Invalid argument Dec 01 14:34:31 volumio-sala volumio-cpu-tweak[1060]: pid 819's current affinity mask: c Dec 01 14:34:31 volumio-sala volumio-cpu-tweak[1060]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 01 14:34:31 volumio-sala volumio-cpu-tweak[1060]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 01 14:34:31 volumio-sala systemd[1]: volumio_cpu_tweak.service: Succeeded. Dec 01 14:34:31 volumio-sala volumio-time-update[609]: volumio-time-update-util: Fetching time from Volumio... Dec 01 14:34:32 volumio-sala volumio-time-update[609]: volumio-time-update-util: Setting system time to: 2024-12-01 14:35:08 Dec 01 14:34:32 volumio-sala sudo[1083]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2024-12-01 14:35:08 Dec 01 14:34:32 volumio-sala sudo[1083]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:34:32 volumio-sala dbus-daemon[664]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=1084 comm="timedatectl set-time 2024-12-01 14:35:08 ") Dec 01 14:34:32 volumio-sala systemd[1]: Starting Time & Date Service... Dec 01 14:34:32 volumio-sala ntpd[1061]: Soliciting pool server 89.46.74.148 Dec 01 14:34:32 volumio-sala dbus-daemon[664]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 01 14:34:32 volumio-sala systemd[1]: Started Time & Date Service. Dec 01 14:35:08 volumio-sala systemd-timedated[1085]: Changed local time to Sun Dec 1 14:35:08 2024 Dec 01 14:35:08 volumio-sala sudo[1083]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:08 volumio-sala volumio-time-update[609]: volumio-time-update-util: System time updated successfully. Dec 01 14:35:08 volumio-sala systemd[1]: Started Volumio Time Update Utility. Dec 01 14:35:08 volumio-sala ntpd[1061]: Soliciting pool server 212.6.50.243 Dec 01 14:35:09 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:09 volumio-sala volumio[1058]: info: ----- Volumio3 ---- Dec 01 14:35:09 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:09 volumio-sala volumio[1058]: info: ----- System startup ---- Dec 01 14:35:09 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:09 volumio-sala ntpd[1061]: Soliciting pool server 212.45.144.88 Dec 01 14:35:09 volumio-sala ntpd[1061]: Soliciting pool server 212.45.144.206 Dec 01 14:35:10 volumio-sala volumio[1058]: info: MYVOLUMIO Environment detected Dec 01 14:35:10 volumio-sala systemd[1]: systemd-fsckd.service: Succeeded. Dec 01 14:35:10 volumio-sala volumio[1058]: info: Plugin folders cleanup Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning into folder /volumio/app/plugins/ Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category audio_interface Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category miscellanea Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category music_service Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category plugins.json Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category system_controller Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category user_interface Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning into folder /data/plugins/ Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category music_service Dec 01 14:35:10 volumio-sala volumio[1058]: info: Scanning category system_hardware Dec 01 14:35:10 volumio-sala volumio[1058]: info: Plugin folders cleanup completed Dec 01 14:35:10 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:10 volumio-sala volumio[1058]: info: ----- Core plugins startup ---- Dec 01 14:35:10 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:10 volumio-sala volumio[1058]: info: Loading plugins from folder /volumio/app/plugins/ Dec 01 14:35:10 volumio-sala volumio[1058]: info: Adding plugin upnp to MyMusic Plugins Dec 01 14:35:10 volumio-sala volumio[1058]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 01 14:35:10 volumio-sala volumio[1058]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 01 14:35:10 volumio-sala volumio[1058]: info: Loading plugins from folder /data/plugins/ Dec 01 14:35:10 volumio-sala volumio[1058]: info: Loading plugin "system"... Dec 01 14:35:10 volumio-sala volumio[1058]: info: Loading plugin "appearance"... Dec 01 14:35:10 volumio-sala ntpd[1061]: Soliciting pool server 185.19.184.35 Dec 01 14:35:10 volumio-sala ntpd[1061]: Soliciting pool server 212.45.144.3 Dec 01 14:35:10 volumio-sala ntpd[1061]: Soliciting pool server 188.213.165.209 Dec 01 14:35:11 volumio-sala nmbd[775]: [2024/12/01 14:35:11.003008, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 01 14:35:11 volumio-sala nmbd[775]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 01 14:35:11 volumio-sala systemd[1]: Started Samba NMB Daemon. Dec 01 14:35:11 volumio-sala systemd[1]: Starting Samba Winbind Daemon... Dec 01 14:35:11 volumio-sala sh[530]: timed out Dec 01 14:35:11 volumio-sala dhcpcd[572]: timed out Dec 01 14:35:11 volumio-sala sh[530]: dhcpcd exited Dec 01 14:35:11 volumio-sala dhcpcd[572]: dhcpcd exited Dec 01 14:35:11 volumio-sala sh[530]: ifup: failed to bring up eth0 Dec 01 14:35:11 volumio-sala systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 01 14:35:11 volumio-sala systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 01 14:35:11 volumio-sala winbindd[1102]: [2024/12/01 14:35:11.392448, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Dec 01 14:35:11 volumio-sala winbindd[1102]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 01 14:35:11 volumio-sala winbindd[1102]: [2024/12/01 14:35:11.410345, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 01 14:35:11 volumio-sala winbindd[1102]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 01 14:35:11 volumio-sala systemd[1]: Started Samba Winbind Daemon. Dec 01 14:35:11 volumio-sala systemd[1]: Starting Samba SMB Daemon... Dec 01 14:35:11 volumio-sala ntpd[1061]: Soliciting pool server 151.22.209.90 Dec 01 14:35:11 volumio-sala ntpd[1061]: Soliciting pool server 162.159.200.123 Dec 01 14:35:11 volumio-sala ntpd[1061]: Soliciting pool server 162.159.200.1 Dec 01 14:35:11 volumio-sala volumio[1058]: info: Loading plugin "network"... Dec 01 14:35:11 volumio-sala volumio[1058]: info: Refreshing Cached IP Addresses Dec 01 14:35:12 volumio-sala smbd[1108]: [2024/12/01 14:35:12.008242, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 01 14:35:12 volumio-sala smbd[1108]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 01 14:35:12 volumio-sala systemd[1]: Started Samba SMB Daemon. Dec 01 14:35:12 volumio-sala systemd[1]: Reached target Multi-User System. Dec 01 14:35:12 volumio-sala systemd[1]: Reached target Graphical Interface. Dec 01 14:35:12 volumio-sala sudo[1117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 14:35:12 volumio-sala sudo[1115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 01 14:35:12 volumio-sala systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "services"... Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "alsa_controller"... Dec 01 14:35:12 volumio-sala sudo[1115]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:12 volumio-sala sudo[1117]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:12 volumio-sala sudo[1115]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:12 volumio-sala sudo[1128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 01 14:35:12 volumio-sala sudo[1128]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:12 volumio-sala sudo[1117]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:12 volumio-sala systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 01 14:35:12 volumio-sala systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 01 14:35:12 volumio-sala systemd[1]: Startup finished in 16.357s (kernel) + 39.724s (userspace) = 56.081s. Dec 01 14:35:12 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "wizard"... Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "networkfs"... Dec 01 14:35:12 volumio-sala volumio[1058]: info: Starting Udev Watcher for removable devices Dec 01 14:35:12 volumio-sala sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/Musica rete /mnt/NAS/Musica_in_rete Dec 01 14:35:12 volumio-sala sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:12 volumio-sala volumio[1058]: info: Ignoring mount for partition: boot Dec 01 14:35:12 volumio-sala volumio[1058]: info: Ignoring mount for partition: volumio Dec 01 14:35:12 volumio-sala volumio[1058]: info: Ignoring mount for partition: volumio_data Dec 01 14:35:12 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "volumio_command_line_client"... Dec 01 14:35:12 volumio-sala volumio[1058]: info: Plugin upnp is not enabled Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "my_music"... Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "mpd"... Dec 01 14:35:12 volumio-sala kernel: Key type cifs.spnego registered Dec 01 14:35:12 volumio-sala kernel: Key type cifs.idmap registered Dec 01 14:35:12 volumio-sala 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. Dec 01 14:35:12 volumio-sala kernel: CIFS: Attempting to mount //192.168.1.16/Musica rete Dec 01 14:35:12 volumio-sala volumio[1058]: info: Plugin upnp_browser is not enabled Dec 01 14:35:12 volumio-sala volumio[1058]: info: Loading plugin "alarm-clock"... Dec 01 14:35:12 volumio-sala ntpd[1061]: Soliciting pool server 185.157.229.254 Dec 01 14:35:12 volumio-sala ntpd[1061]: Soliciting pool server 95.110.254.234 Dec 01 14:35:13 volumio-sala volumio[1058]: info: Loading plugin "airplay_emulation"... Dec 01 14:35:13 volumio-sala volumio[1058]: info: Starting Shairport Sync Dec 01 14:35:13 volumio-sala volumio[1058]: info: Loading plugin "last_100"... Dec 01 14:35:13 volumio-sala volumio[1058]: info: Loading plugin "webradio"... Dec 01 14:35:13 volumio-sala volumio[1058]: info: Loading plugin "i2s_dacs"... Dec 01 14:35:13 volumio-sala volumio[1058]: info: I2S DAC not set, start Auto-detection Dec 01 14:35:13 volumio-sala volumio[1058]: info: Loading plugin "volumiodiscovery"... Dec 01 14:35:13 volumio-sala volumio[1058]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 01 14:35:13 volumio-sala volumio[1058]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 01 14:35:13 volumio-sala node[1058]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 01 14:35:13 volumio-sala volumio[1058]: *** WARNING *** For more information see Dec 01 14:35:13 volumio-sala volumio[1058]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 01 14:35:13 volumio-sala volumio[1058]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 01 14:35:13 volumio-sala volumio[1058]: *** WARNING *** For more information see Dec 01 14:35:13 volumio-sala node[1058]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 01 14:35:13 volumio-sala node[1058]: *** WARNING *** For more information see Dec 01 14:35:13 volumio-sala node[1058]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 01 14:35:13 volumio-sala node[1058]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 01 14:35:13 volumio-sala node[1058]: *** WARNING *** For more information see Dec 01 14:35:13 volumio-sala volumio[1058]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 01 14:35:13 volumio-sala volumio[1058]: info: Discovery: Started advertising with name: Volumio Sala Dec 01 14:35:13 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 01 14:35:13 volumio-sala volumio[1058]: info: Loading plugin "spop"... Dec 01 14:35:13 volumio-sala ntpd[1061]: Soliciting pool server 93.94.88.51 Dec 01 14:35:13 volumio-sala ntpd[1061]: Soliciting pool server 2a00:6d41:200:2::11 Dec 01 14:35:14 volumio-sala volumio[1058]: info: Loading plugin "gpio-buttons"... Dec 01 14:35:14 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:35:14] [connect] Successful connection Dec 01 14:35:14 volumio-sala systemd[1]: systemd-hostnamed.service: Succeeded. Dec 01 14:35:15 volumio-sala ntpd[1061]: Soliciting pool server 89.46.74.148 Dec 01 14:35:15 volumio-sala volumio[1058]: info: GPIO-Buttons initialized Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "outputs"... Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "albumart"... Dec 01 14:35:15 volumio-sala volumio[1058]: info: Plugin example_plugin is not enabled Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "inputs"... Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "updater_comm"... Dec 01 14:35:15 volumio-sala sudo[1128]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:15 volumio-sala volumio[1058]: info: Plugin mpdemulation is not enabled Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "rest_api"... Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "websocket"... Dec 01 14:35:15 volumio-sala volumio[1058]: info: Starting Socket.io Server version 2.3.0 Dec 01 14:35:15 volumio-sala volumio[1058]: info: Loading plugin "music_services_shield"... Dec 01 14:35:15 volumio-sala volumio[1058]: Forking 3 albumart workers Dec 01 14:35:15 volumio-sala ntpd[1061]: Soliciting pool server 93.94.88.50 Dec 01 14:35:16 volumio-sala volumio[1058]: info: Applying required configuration parameters for plugin music_services_shield Dec 01 14:35:16 volumio-sala volumio[1058]: info: Loading i18n strings for locale it Dec 01 14:35:16 volumio-sala volumio[1058]: Starting albumart workers Dec 01 14:35:16 volumio-sala volumio[1058]: Updating browse sources language Dec 01 14:35:16 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 14:35:17 volumio-sala ntpd[1061]: receive: Unexpected origin timestamp 0xeaf6e494.dc18ac28 does not match aorg 0000000000.00000000 from server@185.157.229.254 xmt 0xeaf6e495.827c7a46 Dec 01 14:35:17 volumio-sala ntpd[1061]: receive: Unexpected origin timestamp 0xeaf6e494.dc1b81fc does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xeaf6e495.82668b5e Dec 01 14:35:17 volumio-sala ntpd[1061]: receive: Unexpected origin timestamp 0xeaf6e494.dc16dfef does not match aorg 0000000000.00000000 from server@95.110.254.234 xmt 0xeaf6e495.8272a686 Dec 01 14:35:17 volumio-sala ntpd[1061]: receive: Unexpected origin timestamp 0xeaf6e494.dc1a4033 does not match aorg 0000000000.00000000 from server@151.22.209.90 xmt 0xeaf6e495.85bfdc17 Dec 01 14:35:17 volumio-sala ntpd[1061]: receive: Unexpected origin timestamp 0xeaf6e494.dc12a1f6 does not match aorg 0000000000.00000000 from server@93.94.88.50 xmt 0xeaf6e495.85439db4 Dec 01 14:35:17 volumio-sala ntpd[1061]: receive: Unexpected origin timestamp 0xeaf6e494.dc1ed744 does not match aorg 0000000000.00000000 from server@212.6.50.243 xmt 0xeaf6e495.86f305a3 Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::initPlayerControls Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: Express server listening on port 3000 Dec 01 14:35:17 volumio-sala volumio[1058]: [Metrics] WebUI: 8s 594.77ms Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreStateMachine::resetVolumioState Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreStateMachine::getcurrentVolume Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioRetrievevolume Dec 01 14:35:17 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:17 volumio-sala volumio[1058]: Starting albumart workers Dec 01 14:35:17 volumio-sala volumio[1058]: info: Volumio Network Manager: Network status updated: 2 Dec 01 14:35:17 volumio-sala volumio[1058]: Starting albumart workers Dec 01 14:35:17 volumio-sala volumio-remote-updater[640]: [2024-12-01 14:35:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1733060114 101 Dec 01 14:35:18 volumio-sala volumio[1058]: 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 Dec 01 14:35:18 volumio-sala volumio[1058]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 01 14:35:18 volumio-sala volumio[1058]: info: VolumeController:: Volume=100 Mute =false Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::pushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioPushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::updateTrackBlock Dec 01 14:35:18 volumio-sala volumio[1058]: info: CorePlayQueue::getTrackBlock Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioRetrievevolume Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::setRepeat null single undefined Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::pushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioPushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::setRandom null Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::pushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioPushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: Setting Device type: Raspberry PI Dec 01 14:35:18 volumio-sala volumio[1058]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 01 14:35:18 volumio-sala volumio[1058]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Dec 01 14:35:18 volumio-sala volumio[1058]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 01 14:35:18 volumio-sala volumio[1058]: info: Discovery: adding 514c64ab-07ad-4820-a9ba-65e30f26d22a Dec 01 14:35:18 volumio-sala volumio[1058]: info: Discovery: Found device Volumio Sala Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioGetState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:18 volumio-sala volumio[1058]: info: VolumeController:: Volume=100 Mute =false Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreStateMachine::pushState Dec 01 14:35:18 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:18 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioPushState Dec 01 14:35:19 volumio-sala kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 01 14:35:19 volumio-sala kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Dec 01 14:35:19 volumio-sala sudo[1146]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:19 volumio-sala volumio[1058]: info: Cannot mount NAS Musica_in_rete at system boot, trial number 1 ,retrying in 5 seconds Dec 01 14:35:19 volumio-sala volumio[1058]: info: Completed loading Core Plugins Dec 01 14:35:19 volumio-sala volumio[1058]: info: Preparing to generate the ALSA configuration file Dec 01 14:35:19 volumio-sala volumio[1058]: info: Asound.conf file written Dec 01 14:35:19 volumio-sala sudo[1235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 01 14:35:19 volumio-sala sudo[1235]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:19 volumio-sala sudo[1235]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:19 volumio-sala volumio[1058]: info: Output device has changed, restarting MPD Dec 01 14:35:19 volumio-sala sudo[1240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 01 14:35:19 volumio-sala sudo[1240]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:19 volumio-sala volumio[1058]: info: Output device has changed, restarting Shairport Sync Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:19 volumio-sala sudo[1240]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:19 volumio-sala sudo[1243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 01 14:35:19 volumio-sala sudo[1243]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:19 volumio-sala systemd[1]: musicservicesshield.service: Succeeded. Dec 01 14:35:19 volumio-sala systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Dec 01 14:35:19 volumio-sala systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Dec 01 14:35:19 volumio-sala systemd[1]: Stopping Music Player Daemon... Dec 01 14:35:19 volumio-sala volumio[1058]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 01 14:35:19 volumio-sala volumio[1058]: info: ___________ START PLUGINS ___________ Dec 01 14:35:19 volumio-sala volumio[1058]: info: ControllerMpd::onStart: Initializing MPD Dec 01 14:35:19 volumio-sala volumio[1058]: info: Creating MPD Configuration file Dec 01 14:35:19 volumio-sala sudo[1249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:19 volumio-sala sudo[1249]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:19 volumio-sala sudo[1249]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:19 volumio-sala sudo[1251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 01 14:35:19 volumio-sala sudo[1251]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:19 volumio-sala volumio[1058]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:19 volumio-sala systemd[1]: mpd.service: Succeeded. Dec 01 14:35:19 volumio-sala systemd[1]: Stopped Music Player Daemon. Dec 01 14:35:19 volumio-sala volumio[1058]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 01 14:35:19 volumio-sala volumio[1058]: info: [1733060119804] CoreMusicLibrary::Adding element Last_100 Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 01 14:35:19 volumio-sala volumio[1058]: info: [1733060119810] CoreMusicLibrary::Adding element Webradio Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 14:35:19 volumio-sala volumio[1058]: info: Initializing BBC Radios Dec 01 14:35:19 volumio-sala systemd[1]: Starting Music Player Daemon... Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:19 volumio-sala volumio[1058]: info: Creating Spotify config file Dec 01 14:35:19 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:19 volumio-sala sudo[1258]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 01 14:35:19 volumio-sala sudo[1258]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:19 volumio-sala sudo[1258]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:19 volumio-sala volumio[1058]: info: GPIO-Buttons: Reading config and creating triggers... Dec 01 14:35:20 volumio-sala volumio[1058]: info: Volumio Calling Home Dec 01 14:35:20 volumio-sala volumio[1058]: info: GPIO-Buttons started Dec 01 14:35:20 volumio-sala volumio[1058]: info: MPD Permissions set Dec 01 14:35:20 volumio-sala volumio[1058]: info: MPD Permissions set Dec 01 14:35:20 volumio-sala volumio[1058]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 01 14:35:20 volumio-sala volumio[1058]: info: Spotify config file written Dec 01 14:35:20 volumio-sala sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 01 14:35:20 volumio-sala sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:20 volumio-sala sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Dec 01 14:35:20 volumio-sala sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 14:35:20 volumio-sala volumio[1058]: info: No need to fix Spotify hosts Dec 01 14:35:20 volumio-sala volumio[1058]: info: Volumio called home Dec 01 14:35:20 volumio-sala volumio[1058]: info: Starting Shairport Sync Dec 01 14:35:20 volumio-sala volumio[1058]: info: Starting Shairport Sync Dec 01 14:35:20 volumio-sala go-librespot[1311]: Librespot-go daemon starting... Dec 01 14:35:20 volumio-sala systemd[1]: Started go-librespot Daemon. Dec 01 14:35:20 volumio-sala sudo[1304]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:20 volumio-sala sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 01 14:35:20 volumio-sala volumio[1058]: info: Starting Shairport Sync Dec 01 14:35:20 volumio-sala sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:20 volumio-sala sudo[1328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 01 14:35:20 volumio-sala sudo[1328]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:20 volumio-sala systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 01 14:35:20 volumio-sala systemd[1]: shairport-sync.service: Succeeded. Dec 01 14:35:20 volumio-sala systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 01 14:35:20 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioGetState Dec 01 14:35:20 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:20 volumio-sala sudo[1337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 01 14:35:20 volumio-sala sudo[1337]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:20 volumio-sala systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 01 14:35:20 volumio-sala sudo[1326]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:20 volumio-sala systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 01 14:35:20 volumio-sala systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 01 14:35:20 volumio-sala systemd[1]: shairport-sync.service: Succeeded. Dec 01 14:35:20 volumio-sala systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 01 14:35:20 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:20+01:00" level=info msg="generated new device id: ae6e9d682832abdbe8539cfe366ab85fea255765" Dec 01 14:35:20 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:20+01:00" level=debug msg="stored credentials found for nik_audio" Dec 01 14:35:20 volumio-sala systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 01 14:35:20 volumio-sala sudo[1328]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:20 volumio-sala systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 01 14:35:20 volumio-sala systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 01 14:35:21 volumio-sala systemd[1]: shairport-sync.service: Succeeded. Dec 01 14:35:21 volumio-sala systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 01 14:35:21 volumio-sala systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 01 14:35:21 volumio-sala sudo[1337]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:21 volumio-sala volumio[1058]: info: Shairport-Sync Started Dec 01 14:35:21 volumio-sala volumio[1058]: Error adding Membership: Error: addMembership EINVAL Dec 01 14:35:21 volumio-sala volumio[1058]: info: Shairport-Sync Started Dec 01 14:35:21 volumio-sala volumio[1058]: info: Shairport-Sync Started Dec 01 14:35:21 volumio-sala volumio[1058]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 01 14:35:21 volumio-sala volumio[1058]: SPOTIFY: BQAEtyDK_XME4-PRM-oTFa-fBZ6b1QqFQJ3aGWmaFdnRlfXdqxZqG-AytdbvezgdWGGRNGmgIK4jUi7uFamcwGv_XO2z2Y48PpfF3ea9vVV6YfAak4Xn4e_eH7Z-Qw6fv-9m_T5anBORk3idC6kD-UgefcaLMzrdazisT3hD7GkZHfy0BrCUR-mpSE1LJGrmxiuNH6MVVfj14XmNp8w-w8b2df13nZl6lIN6TtM4dudxlq0p5DmXVT_QAQ Dec 01 14:35:21 volumio-sala volumio[1058]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 01 14:35:21 volumio-sala volumio[1058]: info: New Spotify access token = BQAEtyDK_XME4-PRM-oTFa-fBZ6b1QqFQJ3aGWmaFdnRlfXdqxZqG-AytdbvezgdWGGRNGmgIK4jUi7uFamcwGv_XO2z2Y48PpfF3ea9vVV6YfAak4Xn4e_eH7Z-Qw6fv-9m_T5anBORk3idC6kD-UgefcaLMzrdazisT3hD7GkZHfy0BrCUR-mpSE1LJGrmxiuNH6MVVfj14XmNp8w-w8b2df13nZl6lIN6TtM4dudxlq0p5DmXVT_QAQ Dec 01 14:35:21 volumio-sala volumio[1058]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 01 14:35:21 volumio-sala mpd[1272]: Dec 01 14:35 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 01 14:35:21 volumio-sala volumio[1058]: SPOTIFY: User informations: {"country":"IT","display_name":"Nik Ko","email":"nik.audio@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/nik_audio"},"followers":{"href":null,"total":83},"href":"https://api.spotify.com/v1/users/nik_audio","id":"nik_audio","images":[{"height":300,"url":"https://scontent-ams4-1.xx.fbcdn.net/v/t1.6435-1/205008670_10226829971678710_5092480976623625402_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=109&ccb=1-7&_nc_sid=3e9727&_nc_ohc=lo0fBjE6U5cQ7kNvgGopHEs&_nc_zt=24&_nc_ht=scontent-ams4-1.xx&edm=AP4hL3IEAAAA&_nc_gid=ALpgcSr6wE0kolVKi20i5z-&oh=00_AYBBrJozLRzWnEI8ceReFEWKM3OQCPR5-mfWmfTaxUOb1w&oe=6773765C","width":300},{"height":64,"url":"https://scontent-ams4-1.xx.fbcdn.net/v/t1.6435-1/205008670_10226829971678710_5092480976623625402_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=109&ccb=1-7&_nc_sid=6738e8&_nc_ohc=lo0fBjE6U5cQ7kNvgGopHEs&_nc_zt=24&_nc_ht=scontent-ams4-1.xx&edm=AP4hL3IEAAAA&_nc_gid=ALpgcSr6wE0kolVKi20i5z-&oh=00_AYDEBjqTIXL-t7XfrAS_eRB3k8PCdjOA573FG2jeSU2vhQ&oe=6773765C","width":64}],"product":"premium","type":"user","uri":"spotify:user:nik_audio"} Dec 01 14:35:21 volumio-sala volumio[1058]: info: Spotify Successfully logged in Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 01 14:35:21 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 01 14:35:21 volumio-sala volumio[1058]: info: [1733060121445] CoreMusicLibrary::Adding element Spotify Dec 01 14:35:21 volumio-sala volumio[1058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 14:35:21 volumio-sala volumio[1058]: Cannot find translation for source Spotify Dec 01 14:35:21 volumio-sala systemd[1]: Started Music Player Daemon. Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=debug msg="zeroconf server listening on port 44303" Dec 01 14:35:21 volumio-sala sudo[1243]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:21 volumio-sala sudo[1251]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=debug msg="obtained new client token: AAAlfrxHkeDFOxPNWxHE8WnY7eUvn5VUgCkgvOIW+qta9hV1BrL5mazAxwMH0Auseikk9AarTZ7TjwtmmY++ojqEudYqDy/j7mW7LMJlBlEPF2r95IQVpBF4/P4AeC5UuOzxFiB8hd++jI/Ag/2EIjP0/xy0o5UNk7At24+4DLr/8aE0Rs6WHqWG9R1eR8v+GgtgfZexmX9IXcHvu4+FOZDdYQWLl+96CXc65Z0ydudvHxIwSYy7oQjcufg=" Dec 01 14:35:21 volumio-sala systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Dec 01 14:35:21 volumio-sala volumio[1058]: error: MPD error: The expression evaluated to a falsy value: Dec 01 14:35:21 volumio-sala volumio[1058]: assert.ok(self.idling) Dec 01 14:35:21 volumio-sala volumio[1058]: error: The expression evaluated to a falsy value: Dec 01 14:35:21 volumio-sala volumio[1058]: assert.ok(self.idling) Dec 01 14:35:21 volumio-sala volumio[1058]: error: updateQueue error: null Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Dec 01 14:35:21 volumio-sala sudo[1299]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:21 volumio-sala volumio[1058]: info: MPD running with PID1272 Dec 01 14:35:21 volumio-sala volumio[1058]: ,establishing connection Dec 01 14:35:21 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:21+01:00" level=debug msg="completed keyexchange" Dec 01 14:35:21 volumio-sala volumio[1058]: info: Completed starting Core Plugins Dec 01 14:35:21 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:21 volumio-sala volumio[1058]: info: ----- MyVolumio plugins startup ---- Dec 01 14:35:21 volumio-sala volumio[1058]: info: ------------------------------------------- Dec 01 14:35:21 volumio-sala volumio[1058]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 01 14:35:21 volumio-sala volumio[1058]: error: updateQueue error: null Dec 01 14:35:21 volumio-sala sudo[1372]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh Dec 01 14:35:21 volumio-sala sudo[1372]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:22 volumio-sala volumio[1353]: cset: --> shielding system active with Dec 01 14:35:22 volumio-sala volumio[1353]: cset: "system" cpuset of CPUSPEC(0-1) with 110 tasks running Dec 01 14:35:22 volumio-sala volumio[1353]: cset: "user" cpuset of CPUSPEC(2-3) with 3 tasks running Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="completed challenge" Dec 01 14:35:22 volumio-sala systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Dec 01 14:35:22 volumio-sala systemd[1]: Reloading. Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="authenticated as nik_audio" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="authenticated as nik_audio" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="dealer connection opened" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="initializing zeroconf session, username: nik_audio" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="autoplay enabled: false" Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="received connection id: MDU1MDZlNDYtOTAwYy00MDUwLTgxNjUtY2FlOGVhMmMzOTFkK2RlYWxlcit0Y3A6Ly8wYWNhNThiZi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNjQwRjM3MjE1NDcwQjlBREE4QTQyMTMxNDkwNjY4NUY3RUFBMzQ1QUVCREEzNEM2OEY5REFGMTY3MzhCODQ5Mw==" Dec 01 14:35:22 volumio-sala 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. Dec 01 14:35:22 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:22+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 01 14:35:22 volumio-sala systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Dec 01 14:35:22 volumio-sala sudo[1372]: pam_unix(sudo:session): session closed for user root Dec 01 14:35:22 volumio-sala volumio[1058]: info: succeeded Dec 01 14:35:24 volumio-sala volumio[1058]: info: go-librespot daemon successfully initialized Dec 01 14:35:24 volumio-sala sudo[1417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/Musica rete /mnt/NAS/Musica_in_rete Dec 01 14:35:24 volumio-sala sudo[1417]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 14:35:24 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:24+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 01 14:35:24 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:24+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" Dec 01 14:35:24 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:24+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 01 14:35:24 volumio-sala kernel: CIFS: Attempting to mount //192.168.1.16/Musica rete Dec 01 14:35:24 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:24+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2759" Dec 01 14:35:25 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 01 14:35:25 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:25+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 340" Dec 01 14:35:26 volumio-sala volumio[1058]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 01 14:35:27 volumio-sala volumio[1058]: info: Initializing connection to go-librespot Websocket Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="new websocket client" Dec 01 14:35:27 volumio-sala volumio[1058]: info: Connection to go-librespot Websocket established Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="handling transfer player command from be5cf31c0a3786429a4513463992a2f4bc20b0ec" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="resolved context of track" uri="spotify:station:track:1nzVUWpzK0rYpHa4c5Bqzf" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:station:track:1nzVUWpzK0rYpHa4c5Bqzf" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="loading track (paused: false, position: 3387ms)" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=trace msg="emitting websocket event: will_play" Dec 01 14:35:27 volumio-sala volumio[1058]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4lpvDCDr0JDcGMhGh6gOfW","play_origin":""}} Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="selected format OGG_VORBIS_320 (1af178b24f366011e7898665f2fd7a52de555614)" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="requested aes key for file 1af178b24f366011e7898665f2fd7a52de555614, gid: 4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2787" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="fetched first chunk of 13, total size is 6646244 bytes" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=trace msg="seek to 3387ms (diff: 99ms, samples: 149366, bytes: 140292)" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5020 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=debug msg="created new output device" Dec 01 14:35:27 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:27+01:00" level=info msg="loaded track \"Estate (From the Netflix Original Series \\\"Summertime\\\")\" (paused: false, position: 3387ms, duration: 152550ms, prefetched: false)" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=trace msg="scheduling prefetch in 119s" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=trace msg="emitting websocket event: metadata" Dec 01 14:35:28 volumio-sala volumio[1058]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4lpvDCDr0JDcGMhGh6gOfW","name":"Estate (From the Netflix Original Series \"Summertime\")","artist_names":["Giorgio Poi"],"album_name":"Estate (From the Netflix Original Series \"Summertime\")","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f3ce8c735f7a5f34b60127eb","position":3387,"duration":152550,"release_date":"year:2020 month:7 day:17","track_number":1,"disc_number":1}} Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=trace msg="emitting websocket event: active" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="sending successful reply for dealer request" Dec 01 14:35:28 volumio-sala volumio[1058]: SPOTIFY: received: {"type":"active","data":null} Dec 01 14:35:28 volumio-sala volumio[1058]: info: Aligning Spotify Volume to Volumio Volume Dec 01 14:35:28 volumio-sala volumio[1058]: info: CoreCommandRouter::volumioGetState Dec 01 14:35:28 volumio-sala volumio[1058]: info: CorePlayQueue::getTrack 0 Dec 01 14:35:28 volumio-sala volumio[1058]: info: Setting Spotify Volume from Volumio: 100 Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1840" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:4lpvDCDr0JDcGMhGh6gOfW" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=trace msg="emitting websocket event: playing" Dec 01 14:35:28 volumio-sala volumio[1058]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4lpvDCDr0JDcGMhGh6gOfW","play_origin":""}} Dec 01 14:35:28 volumio-sala volumio[1058]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 01 14:35:28 volumio-sala go-librespot[1311]: time="2024-12-01T14:35:28+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 01 14:35:28 volumio-sala volumio[1058]: TypeError: Cannot read property 'service' of undefined Dec 01 14:35:28 volumio-sala volumio[1058]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Dec 01 14:35:28 volumio-sala volumio[1058]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Dec 01 14:35:28 volumio-sala volumio[1058]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Dec 01 14:35:28 volumio-sala volumio[1058]: at WebSocket.emit (events.js:315:20) Dec 01 14:35:28 volumio-sala volumio[1058]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Dec 01 14:35:28 volumio-sala volumio[1058]: at Receiver.emit (events.js:315:20) Dec 01 14:35:28 volumio-sala volumio[1058]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Dec 01 14:35:28 volumio-sala volumio[1058]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Dec 01 14:35:28 volumio-sala volumio[1058]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Dec 01 14:35:28 volumio-sala volumio[1058]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Dec 01 14:35:28 volumio-sala volumio[1058]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 14:35:28 volumio-sala sudo[1430]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-12-01 14:34 Dec 01 14:35:28 volumio-sala sudo[1430]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"