Jan 26 15:00:11 volumio-100 ntpd[976]: CLOCK: time stepped by 81779.275789 Jan 26 15:00:11 volumio-100 ntpd[976]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jan 26 15:00:11 volumio-100 systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jan 26 15:00:11 volumio-100 systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jan 26 15:00:11 volumio-100 systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jan 26 15:00:11 volumio-100 systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jan 26 15:00:11 volumio-100 systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jan 26 15:00:11 volumio-100 volumio[1158]: info: Loading plugin "network"... Jan 26 15:00:11 volumio-100 volumio[1158]: info: Refreshing Cached IP Addresses Jan 26 15:00:11 volumio-100 volumio[1158]: info: Loading plugin "services"... Jan 26 15:00:11 volumio-100 sudo[1321]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 15:00:11 volumio-100 sudo[1321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "alsa_controller"... Jan 26 15:00:12 volumio-100 sudo[1323]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 15:00:12 volumio-100 sudo[1329]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 15:00:12 volumio-100 sudo[1329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:12 volumio-100 sudo[1321]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:12 volumio-100 sudo[1323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:12 volumio-100 sudo[1323]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:12 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "wizard"... Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "networkfs"... Jan 26 15:00:12 volumio-100 volumio[1158]: info: Starting Udev Watcher for removable devices Jan 26 15:00:12 volumio-100 volumio[1158]: info: Ignoring mount for partition: boot Jan 26 15:00:12 volumio-100 volumio[1158]: info: Ignoring mount for partition: volumio Jan 26 15:00:12 volumio-100 volumio[1158]: info: Ignoring mount for partition: volumio_data Jan 26 15:00:12 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "volumio_command_line_client"... Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "upnp"... Jan 26 15:00:12 volumio-100 volumio[1158]: info: [1769436012340] Starting Upmpd Daemon Jan 26 15:00:12 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "my_music"... Jan 26 15:00:12 volumio-100 volumio[1158]: info: Loading plugin "mpd"... Jan 26 15:00:12 volumio-100 sudo[1356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=joancarles,password=lleida123,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.31.124/Musica /mnt/NAS/Nas Jan 26 15:00:12 volumio-100 sudo[1356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:12 volumio-100 kernel: netfs: FS-Cache loaded Jan 26 15:00:12 volumio-100 kernel: Key type cifs.spnego registered Jan 26 15:00:12 volumio-100 kernel: Key type cifs.idmap registered Jan 26 15:00:12 volumio-100 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. Jan 26 15:00:12 volumio-100 kernel: CIFS: Attempting to mount //192.168.31.124/Musica Jan 26 15:00:12 volumio-100 sudo[1329]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:13 volumio-100 volumio[1158]: info: Loading plugin "upnp_browser"... Jan 26 15:00:13 volumio-100 ntpd[976]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jan 26 15:00:13 volumio-100 ntpd[976]: DNS: Pool taking: 194.164.164.175 Jan 26 15:00:13 volumio-100 ntpd[976]: DNS: Pool taking: 178.215.228.24 Jan 26 15:00:13 volumio-100 ntpd[976]: DNS: Pool taking: 82.165.173.235 Jan 26 15:00:13 volumio-100 ntpd[976]: DNS: Pool taking: 172.233.111.193 Jan 26 15:00:13 volumio-100 ntpd[976]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jan 26 15:00:13 volumio-100 sudo[1356]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:13 volumio-100 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Jan 26 15:00:13 volumio-100 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 15:00:13 volumio-100 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 15:00:14 volumio-100 upmpdcli[1393]: Could not open config: /tmp/upmpdcli.conf Jan 26 15:00:14 volumio-100 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 26 15:00:14 volumio-100 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 26 15:00:14 volumio-100 ntpd[976]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 15:00:15 volumio-100 volumio-remote-updater[680]: [2026-01-26 15:00:15] [connect] Successful connection Jan 26 15:00:15 volumio-100 volumio[1158]: info: Starting UPNP Browser Jan 26 15:00:15 volumio-100 volumio[1158]: info: Loading plugin "alarm-clock"... Jan 26 15:00:16 volumio-100 volumio[1158]: info: Plugin airplay_emulation is not enabled Jan 26 15:00:16 volumio-100 volumio[1158]: info: Loading plugin "last_100"... Jan 26 15:00:16 volumio-100 volumio[1158]: info: Loading plugin "webradio"... Jan 26 15:00:16 volumio-100 volumio[1158]: info: Loading plugin "i2s_dacs"... Jan 26 15:00:16 volumio-100 volumio[1158]: info: Loading plugin "volumiodiscovery"... Jan 26 15:00:16 volumio-100 volumio[1158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 15:00:16 volumio-100 volumio[1158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:00:16 volumio-100 volumio[1158]: *** WARNING *** For more information see Jan 26 15:00:16 volumio-100 volumio[1158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 15:00:16 volumio-100 volumio[1158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:00:16 volumio-100 volumio[1158]: *** WARNING *** For more information see Jan 26 15:00:16 volumio-100 node[1158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 15:00:16 volumio-100 node[1158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:00:16 volumio-100 node[1158]: *** WARNING *** For more information see Jan 26 15:00:16 volumio-100 node[1158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 15:00:16 volumio-100 node[1158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:00:16 volumio-100 node[1158]: *** WARNING *** For more information see Jan 26 15:00:16 volumio-100 volumio[1158]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 15:00:16 volumio-100 volumio[1158]: info: Discovery: Started advertising with name: Volumio 100 Jan 26 15:00:16 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 15:00:16 volumio-100 volumio[1158]: info: Loading plugin "spop"... Jan 26 15:00:17 volumio-100 ntpd[976]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jan 26 15:00:17 volumio-100 ntpd[976]: DNS: Pool taking: 195.95.153.43 Jan 26 15:00:17 volumio-100 ntpd[976]: DNS: Pool taking: 5.250.184.159 Jan 26 15:00:17 volumio-100 ntpd[976]: DNS: Pool taking: 162.159.200.1 Jan 26 15:00:17 volumio-100 ntpd[976]: DNS: Pool taking: 5.250.191.170 Jan 26 15:00:17 volumio-100 ntpd[976]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jan 26 15:00:18 volumio-100 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 26 15:00:18 volumio-100 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jan 26 15:00:19 volumio-100 volumio[1158]: info: Loading plugin "ytcr"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "outputs"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "albumart"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Plugin example_plugin is not enabled Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "inputs"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "updater_comm"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Plugin mpdemulation is not enabled Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "rest_api"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "websocket"... Jan 26 15:00:23 volumio-100 volumio[1158]: info: Starting Socket.io Server version 1.7.4 Jan 26 15:00:23 volumio-100 volumio[1158]: info: Loading plugin "fusiondsp"... Jan 26 15:00:25 volumio-100 volumio[1158]: info: Applying required configuration parameters for plugin fusiondsp Jan 26 15:00:25 volumio-100 volumio[1432]: Forking 3 albumart workers Jan 26 15:00:25 volumio-100 volumio[1158]: info: Loading i18n strings for locale ca Jan 26 15:00:25 volumio-100 volumio[1158]: Updating browse sources language Jan 26 15:00:25 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::initPlayerControls Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 15:00:27 volumio-100 volumio[1158]: Express server listening on port 3000 Jan 26 15:00:27 volumio-100 volumio[1158]: [Metrics] WebUI: 22s 309.41ms Jan 26 15:00:28 volumio-100 volumio[1158]: info: CoreStateMachine::resetVolumioState Jan 26 15:00:28 volumio-100 volumio[1158]: info: CoreStateMachine::getcurrentVolume Jan 26 15:00:28 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 15:00:28 volumio-100 sudo[1479]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 15:00:28 volumio-100 sudo[1477]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 15:00:28 volumio-100 sudo[1477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:28 volumio-100 sudo[1479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:28 volumio-100 sudo[1477]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:28 volumio-100 sudo[1479]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:28 volumio-100 volumio[1158]: info: Volumio Network Manager: Network status updated: 2 Jan 26 15:00:29 volumio-100 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Jan 26 15:00:29 volumio-100 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 15:00:29 volumio-100 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 15:00:29 volumio-100 upmpdcli[1482]: :3:../libupnpp/upnpplib.cxx:273::LibUPnP: Using IPV4 192.168.31.126 port 49152 IPV6 port 49152 Jan 26 15:00:29 volumio-100 upmpdcli[1482]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection refused Jan 26 15:00:29 volumio-100 upmpdcli[1482]: :2:../src/main.cxx:728::MPD connection failed Jan 26 15:00:30 volumio-100 volumio-remote-updater[680]: [2026-01-26 15:00:30] [connect] Successful connection Jan 26 15:00:30 volumio-100 volumio[1158]: info: VolumeController:: Volume=66 Mute =false Jan 26 15:00:30 volumio-100 volumio[1158]: info: CoreStateMachine::pushState Jan 26 15:00:30 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:30 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:00:30 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioPushState Jan 26 15:00:30 volumio-100 volumio[1158]: info: CoreStateMachine::updateTrackBlock Jan 26 15:00:30 volumio-100 volumio[1158]: info: CorePlayQueue::getTrackBlock Jan 26 15:00:30 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 15:00:30 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:00:30 volumio-100 volumio[1158]: info: Reloading queue from file Jan 26 15:00:30 volumio-100 volumio-remote-updater[680]: [2026-01-26 15:00:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769436030 101 Jan 26 15:00:30 volumio-100 volumio[1158]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreStateMachine::setRepeat null single undefined Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreStateMachine::pushState Jan 26 15:00:31 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioPushState Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreStateMachine::setRandom null Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreStateMachine::pushState Jan 26 15:00:31 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioPushState Jan 26 15:00:31 volumio-100 volumio[1158]: info: Setting Device type: Raspberry PI Jan 26 15:00:31 volumio-100 upmpdcli[1482]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection refused Jan 26 15:00:31 volumio-100 upmpdcli[1482]: :2:../src/main.cxx:728::MPD connection failed Jan 26 15:00:31 volumio-100 volumio[1158]: info: Completed loading Core Plugins Jan 26 15:00:31 volumio-100 volumio[1158]: info: Preparing to generate the ALSA configuration file Jan 26 15:00:31 volumio-100 volumio[1158]: info: VolumeController:: Volume=66 Mute =false Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreStateMachine::pushState Jan 26 15:00:31 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:31 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioPushState Jan 26 15:00:31 volumio-100 volumio[1158]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 26 15:00:31 volumio-100 volumio[1158]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 26 15:00:31 volumio-100 volumio[1158]: info: Reading ALSA contributions from plugins. Jan 26 15:00:31 volumio-100 sudo[1506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 15:00:31 volumio-100 sudo[1506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:32 volumio-100 volumio[1158]: info: Asound.conf file unchanged, so no further update is needed Jan 26 15:00:32 volumio-100 volumio[1158]: info: Output device has changed, restarting MPD Jan 26 15:00:32 volumio-100 sudo[1506]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:32 volumio-100 volumio[1158]: info: ___________ START PLUGINS ___________ Jan 26 15:00:32 volumio-100 volumio[1158]: info: ControllerMpd::onStart: Initializing MPD Jan 26 15:00:32 volumio-100 volumio[1158]: info: Creating MPD Configuration file Jan 26 15:00:32 volumio-100 sudo[1510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 15:00:32 volumio-100 sudo[1510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:32 volumio-100 sudo[1510]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:32 volumio-100 sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 15:00:32 volumio-100 sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:00:32 volumio-100 volumio[1158]: info: [1769436032546] CoreMusicLibrary::Adding element Media Servers Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:00:32 volumio-100 sudo[1532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 15:00:32 volumio-100 sudo[1532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:32 volumio-100 sudo[1529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 15:00:32 volumio-100 sudo[1529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:32 volumio-100 volumio[1158]: info: UPNP Browser: Client initialized successfully Jan 26 15:00:32 volumio-100 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 15:00:32 volumio-100 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 15:00:32 volumio-100 sudo[1529]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:00:32 volumio-100 volumio[1158]: info: [1769436032798] CoreMusicLibrary::Adding element Last_100 Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:00:32 volumio-100 volumio[1158]: info: [1769436032806] CoreMusicLibrary::Adding element Webradio Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:00:32 volumio-100 systemd[1]: mpd.service: Deactivated successfully. Jan 26 15:00:32 volumio-100 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 15:00:32 volumio-100 systemd[1]: mpd.socket: Deactivated successfully. Jan 26 15:00:32 volumio-100 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 15:00:32 volumio-100 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 15:00:32 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 15:00:32 volumio-100 volumio[1158]: info: Initializing BBC Radios Jan 26 15:00:32 volumio-100 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 15:00:32 volumio-100 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 15:00:33 volumio-100 sudo[1540]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 15:00:33 volumio-100 sudo[1540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 15:00:33 volumio-100 sudo[1547]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 26 15:00:33 volumio-100 sudo[1540]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:33 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 15:00:33 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:00:33 volumio-100 volumio[1158]: info: Creating Spotify config file Jan 26 15:00:33 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:33 volumio-100 volumio[1444]: Starting albumart workers Jan 26 15:00:35 volumio-100 volumio[1443]: Starting albumart workers Jan 26 15:00:36 volumio-100 volumio[1442]: Starting albumart workers Jan 26 15:00:37 volumio-100 upmpdcli[1482]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Jan 26 15:00:37 volumio-100 upmpdcli[1482]: :2:../src/main.cxx:728::MPD connection failed Jan 26 15:00:37 volumio-100 volumio[1158]: info: [ytcr] Data store TTL expired - clearing it... Jan 26 15:00:38 volumio-100 volumio[1158]: info: FusionDsp - CamillaDSP binary found. Jan 26 15:00:38 volumio-100 volumio[1158]: info: Loading i18n strings for locale ca Jan 26 15:00:38 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 26 15:00:38 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:38 volumio-100 volumio[1158]: info: FusionDsp - mixtype--------------------- Hardware Jan 26 15:00:38 volumio-100 volumio[1158]: info: Volumio Calling Home Jan 26 15:00:39 volumio-100 volumio[1158]: info: Preparing to generate the ALSA configuration file Jan 26 15:00:40 volumio-100 mpd[1549]: 2026-01-26T15:00:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 15:00:41 volumio-100 systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 15:00:41 volumio-100 sudo[1516]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:41 volumio-100 sudo[1532]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:41 volumio-100 volumio[1158]: info: camilladsp service started and running in background, instance 1 Jan 26 15:00:41 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:41 volumio-100 volumio[1158]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Jan 26 15:00:41 volumio-100 volumio[1158]: info: FusionDsp loaded Jan 26 15:00:41 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 15:00:41 volumio-100 volumio[1158]: error: FusionDsp - Socket connection not established Jan 26 15:00:41 volumio-100 volumio[1158]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 26 15:00:41 volumio-100 volumio[1158]: info: Adding Signal Path Element [object Object] Jan 26 15:00:41 volumio-100 volumio[1158]: info: Adding fusiondspeq DSP Signal Path Element Jan 26 15:00:41 volumio-100 volumio[1158]: info: FusionDsp - ---- installed callbackRead Jan 26 15:00:42 volumio-100 volumio[1158]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 26 15:00:42 volumio-100 sudo[1591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 26 15:00:42 volumio-100 sudo[1591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:42 volumio-100 volumio[1158]: info: Discovery: adding af98df77-4b75-49a4-bfca-90d41b27230c Jan 26 15:00:42 volumio-100 volumio[1158]: info: Discovery: Found device Volumio 100 Jan 26 15:00:42 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioGetState Jan 26 15:00:42 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:42 volumio-100 volumio[1158]: info: Discovery: this is already registered, af98df77-4b75-49a4-bfca-90d41b27230c Jan 26 15:00:42 volumio-100 volumio[1158]: info: Discovery: Found device Volumio 100 Jan 26 15:00:42 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioGetState Jan 26 15:00:42 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:42 volumio-100 volumio[1158]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 26 15:00:42 volumio-100 volumio[1158]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 26 15:00:42 volumio-100 volumio[1158]: info: Reading ALSA contributions from plugins. Jan 26 15:00:42 volumio-100 systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Jan 26 15:00:42 volumio-100 sudo[1591]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:42 volumio-100 volumio[1158]: info: MPD Permissions set Jan 26 15:00:42 volumio-100 volumio[1158]: info: MPD Permissions set Jan 26 15:00:42 volumio-100 volumio[1158]: info: Upmpdcli Daemon Started Jan 26 15:00:43 volumio-100 volumio[1158]: info: MPD running with PID1549 Jan 26 15:00:43 volumio-100 volumio[1158]: ,establishing connection Jan 26 15:00:43 volumio-100 volumio[1158]: info: Volumio called home Jan 26 15:00:43 volumio-100 volumio[1158]: info: Spotify config file written Jan 26 15:00:43 volumio-100 sudo[1617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 15:00:43 volumio-100 sudo[1617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:43 volumio-100 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 15:00:43 volumio-100 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 15:00:43 volumio-100 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 15:00:43 volumio-100 go-librespot[1619]: go-librespot daemon starting... Jan 26 15:00:43 volumio-100 sudo[1617]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:44 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:44+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 15:00:44 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:44+01:00" level=debug msg="app state loaded" Jan 26 15:00:44 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 15:00:44 volumio-100 volumio[1158]: error: MPD error: The expression evaluated to a falsy value: Jan 26 15:00:44 volumio-100 volumio[1158]: assert.ok(self.idling) Jan 26 15:00:44 volumio-100 volumio[1158]: error: The expression evaluated to a falsy value: Jan 26 15:00:44 volumio-100 volumio[1158]: assert.ok(self.idling) Jan 26 15:00:44 volumio-100 volumio[1158]: error: MPD error: The expression evaluated to a falsy value: Jan 26 15:00:44 volumio-100 volumio[1158]: assert.ok(self.idling) Jan 26 15:00:44 volumio-100 volumio[1158]: error: The expression evaluated to a falsy value: Jan 26 15:00:44 volumio-100 volumio[1158]: assert.ok(self.idling) Jan 26 15:00:44 volumio-100 volumio[1158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:44 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:45 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:00:45 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:45 volumio-100 volumio[1158]: info: No need to fix Spotify hosts Jan 26 15:00:45 volumio-100 upmpdcli[1638]: writing RSA key Jan 26 15:00:46 volumio-100 volumio[1158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 15:00:46 volumio-100 volumio[1158]: error: updateQueue error: null Jan 26 15:00:46 volumio-100 volumio[1158]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 15:00:46 volumio-100 volumio[1158]: SPOTIFY: BQAbCUwF0DnCY0Y2DF_C-2mcpjADCBc5sV48x6krntTA2xbq4xIIlIjxouD2xu55iCUgxaUF8NzKppmB9eg8M5pot2F9lv5O1ARN5Ei8qkCyFiUnk77Hv1xfdeytH7MC21sTtfQ2Uvji1zWH9hTDelbCBJ0Sm3oQYbP7bPlIPQozg0to5XPf4znknSDokNG5arOxHWgjGUeEsHK2SSqQo4mCe3vm5ZakiwYJvpDHn4HFET_Aa79r2JRyYRigbQsHxtsKkReNe0LCl4zWRU4W1DFBB8qXU1meLHa7NHyFPQ27ZBzLOW00ECrU Jan 26 15:00:46 volumio-100 volumio[1158]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 15:00:46 volumio-100 volumio[1158]: info: New Spotify access token = BQAbCUwF0DnCY0Y2DF_C-2mcpjADCBc5sV48x6krntTA2xbq4xIIlIjxouD2xu55iCUgxaUF8NzKppmB9eg8M5pot2F9lv5O1ARN5Ei8qkCyFiUnk77Hv1xfdeytH7MC21sTtfQ2Uvji1zWH9hTDelbCBJ0Sm3oQYbP7bPlIPQozg0to5XPf4znknSDokNG5arOxHWgjGUeEsHK2SSqQo4mCe3vm5ZakiwYJvpDHn4HFET_Aa79r2JRyYRigbQsHxtsKkReNe0LCl4zWRU4W1DFBB8qXU1meLHa7NHyFPQ27ZBzLOW00ECrU Jan 26 15:00:46 volumio-100 volumio[1158]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 15:00:46 volumio-100 volumio[1158]: info: Asound.conf file unchanged, so no further update is needed Jan 26 15:00:46 volumio-100 volumio[1158]: info: Output device has changed, restarting MPD Jan 26 15:00:46 volumio-100 sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 15:00:46 volumio-100 sudo[1643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:46 volumio-100 sudo[1645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 15:00:46 volumio-100 sudo[1645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 15:00:46 volumio-100 sudo[1643]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:46 volumio-100 systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 15:00:46 volumio-100 upmpdcli[1482]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 15:00:46 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 15:00:46 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:46+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 15:00:46 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:46+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 15:00:47 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:47+01:00" level=info msg="zeroconf server listening on port 39105" Jan 26 15:00:47 volumio-100 systemd[1]: mpd.service: Deactivated successfully. Jan 26 15:00:47 volumio-100 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 15:00:47 volumio-100 systemd[1]: mpd.service: Consumed 5.883s CPU time. Jan 26 15:00:47 volumio-100 systemd[1]: mpd.socket: Deactivated successfully. Jan 26 15:00:47 volumio-100 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 15:00:47 volumio-100 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 15:00:47 volumio-100 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 15:00:47 volumio-100 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 15:00:47 volumio-100 sudo[1649]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 15:00:47 volumio-100 sudo[1649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 15:00:47 volumio-100 sudo[1649]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:47 volumio-100 volumio[1158]: info: MPD Permissions set Jan 26 15:00:48 volumio-100 volumio[1158]: error: FusionDsp - Reload WebSocket error: [object Object] Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:00:48 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:00:49 volumio-100 volumio[1158]: info: go-librespot daemon successfully initialized Jan 26 15:00:49 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:49+01:00" level=debug msg="obtained new client token: AABZT85oUBDlPhlG8ZBhG500mLeuPIbqSnOP5/gWRI7wHWf2rAwTfx+xaHGRDvZ90T4fYdIOaySl8HIjJ52ZJuK6L5ZgYMhgzVAx2VmrVZ7n+LtlfUo30QGdXaeIRr4i2BSW5V0RyKeOolGtHs2Gqd0V9HgcSqqxmI5J7El7a5irlXUf5NxN9WG320kpcHDQl8lsN0CrhiwI6CQzUD5GdzAkhv+b4VDC6juMP8YfCsaaN63vdkoFitgEOGs=" Jan 26 15:00:50 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioGetState Jan 26 15:00:50 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:50 volumio-100 mpd[1651]: 2026-01-26T15:00:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 15:00:51 volumio-100 systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 15:00:51 volumio-100 upmpdcli[1482]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Jan 26 15:00:51 volumio-100 upmpdcli[1482]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 15:00:51 volumio-100 sudo[1645]: pam_unix(sudo:session): session closed for user root Jan 26 15:00:51 volumio-100 volumio[1158]: error: updateQueue error: null Jan 26 15:00:51 volumio-100 volumio[1158]: SPOTIFY: User informations: {"country":"ES","display_name":"Joan Carles","email":"jcilergeta@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/w9ip5xntm3gkpvtznqdo06se5"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/w9ip5xntm3gkpvtznqdo06se5","id":"w9ip5xntm3gkpvtznqdo06se5","images":[],"product":"premium","type":"user","uri":"spotify:user:w9ip5xntm3gkpvtznqdo06se5"} Jan 26 15:00:51 volumio-100 volumio[1158]: info: Spotify Successfully logged in Jan 26 15:00:51 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:00:51 volumio-100 volumio[1158]: info: [1769436051768] CoreMusicLibrary::Adding element Spotify Jan 26 15:00:51 volumio-100 volumio[1158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:00:51 volumio-100 volumio[1158]: Cannot find translation for source Spotify Jan 26 15:00:52 volumio-100 volumio[1158]: info: Initializing connection to go-librespot Websocket Jan 26 15:00:52 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:52+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 15:00:52 volumio-100 go-librespot[1620]: time="2026-01-26T15:00:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 15:00:52 volumio-100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 15:00:52 volumio-100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 15:00:52 volumio-100 volumio[1158]: info: Error connecting to go-librespot Websocket: Error: socket hang up Jan 26 15:00:53 volumio-100 volumio[1158]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 15:00:53 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 15:00:53 volumio-100 volumio[1158]: info: VolumeController:: Volume=66 Mute =false Jan 26 15:00:53 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioGetState Jan 26 15:00:53 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:53 volumio-100 volumio[1158]: info: CoreStateMachine::pushState Jan 26 15:00:53 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:00:53 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioPushState Jan 26 15:00:54 volumio-100 volumio[1158]: info: Completed starting Core Plugins Jan 26 15:00:54 volumio-100 volumio[1158]: info: ------------------------------------------- Jan 26 15:00:54 volumio-100 volumio[1158]: info: ----- MyVolumio plugins startup ---- Jan 26 15:00:54 volumio-100 volumio[1158]: info: ------------------------------------------- Jan 26 15:00:54 volumio-100 volumio[1158]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 15:00:55 volumio-100 volumio[1158]: info: Initializing connection to go-librespot Websocket Jan 26 15:00:55 volumio-100 volumio[1158]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 15:00:56 volumio-100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 15:00:56 volumio-100 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 15:00:56 volumio-100 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 15:00:56 volumio-100 go-librespot[1675]: go-librespot daemon starting... Jan 26 15:00:56 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:56+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 15:00:56 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:56+01:00" level=debug msg="app state loaded" Jan 26 15:00:56 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 15:00:58 volumio-100 volumio[1158]: info: Initializing connection to go-librespot Websocket Jan 26 15:00:58 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:58+01:00" level=debug msg="new websocket client" Jan 26 15:00:59 volumio-100 volumio[1158]: info: Connection to go-librespot Websocket established Jan 26 15:00:59 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 15:00:59 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:59+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 15:00:59 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:59+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 15:00:59 volumio-100 go-librespot[1676]: time="2026-01-26T15:00:59+01:00" level=info msg="zeroconf server listening on port 45535" Jan 26 15:01:01 volumio-100 go-librespot[1676]: time="2026-01-26T15:01:01+01:00" level=debug msg="obtained new client token: AABgfn+HyuRErADzhUqHlVm2r0r8jTf9LV81McJr1e7hfLXD3sa+1e0AJg3RRJdFpgMQG0K5SF8OyQkGS0jDk9vZ06WkU0KeoZsKuCAGYG0YP4t6ZXdt7XP0c0uAqMxNmrhNTEOoihE0sxP+R9e4WceXdqpjIfqXjsCNBadF307et7BLEGeSYArmj1t5n4K/8ln83QSL9bojLJoi+KkiaWIq/z404/urNMvoDXUCvtqmkYJhVHezRKX3oJI=" Jan 26 15:01:02 volumio-100 volumio[1158]: info: Getting Spotify volume Jan 26 15:01:02 volumio-100 volumio[1158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 26 15:01:02 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioGetState Jan 26 15:01:02 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:01:02 volumio-100 volumio[1158]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Jan 26 15:01:02 volumio-100 volumio[1158]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 15:01:02 volumio-100 volumio[1158]: SPOTIFY: VOLUMIO VOLUME 66 Jan 26 15:01:02 volumio-100 volumio[1158]: info: Aligning Spotify Volume to Volumio Volume Jan 26 15:01:02 volumio-100 volumio[1158]: info: CoreCommandRouter::volumioGetState Jan 26 15:01:02 volumio-100 volumio[1158]: info: CorePlayQueue::getTrack 0 Jan 26 15:01:02 volumio-100 volumio[1158]: info: Setting Spotify Volume from Volumio: 66 Jan 26 15:01:04 volumio-100 volumio[1158]: SPOTIFY: SETTING SPOTIFY VOLUME 66 Jan 26 15:01:04 volumio-100 volumio[1158]: info: Sending Spotify command with payload to local API: /player/volume Jan 26 15:01:04 volumio-100 go-librespot[1676]: time="2026-01-26T15:01:04+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 15:01:04 volumio-100 go-librespot[1676]: time="2026-01-26T15:01:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.31.126:40718->104.199.65.9:4070: read: connection reset by peer" Jan 26 15:01:04 volumio-100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 15:01:04 volumio-100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 15:01:05 volumio-100 volumio[1158]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 26 15:01:05 volumio-100 volumio[1158]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 15:01:05 volumio-100 volumio[1158]: Error: socket hang up Jan 26 15:01:05 volumio-100 volumio[1158]: at connResetException (node:internal/errors:720:14) Jan 26 15:01:05 volumio-100 volumio[1158]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 15:01:05 volumio-100 volumio[1158]: at Socket.emit (node:events:526:35) Jan 26 15:01:05 volumio-100 volumio[1158]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 15:01:05 volumio-100 volumio[1158]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 15:01:05 volumio-100 volumio[1158]: code: 'ECONNRESET', Jan 26 15:01:05 volumio-100 volumio[1158]: response: undefined Jan 26 15:01:05 volumio-100 volumio[1158]: } Jan 26 15:01:05 volumio-100 volumio[1158]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 15:01:08 volumio-100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 15:01:08 volumio-100 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 15:01:08 volumio-100 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 15:01:08 volumio-100 go-librespot[1710]: go-librespot daemon starting... Jan 26 15:01:08 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:08+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 15:01:08 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:08+01:00" level=debug msg="app state loaded" Jan 26 15:01:08 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 15:01:11 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 15:01:11 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:11+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 15:01:11 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:11+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 15:01:11 volumio-100 go-librespot[1711]: time="2026-01-26T15:01:11+01:00" level=info msg="zeroconf server listening on port 46609" Jan 26 15:01:11 volumio-100 sudo[1719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 15:00' Jan 26 15:01:11 volumio-100 sudo[1719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"