Dec 15 15:25:00 volumio volumio[1181]: info: Starting UPNP Browser Dec 15 15:25:00 volumio volumio[1181]: info: Loading plugin "alarm-clock"... Dec 15 15:25:01 volumio volumio[1181]: info: Loading plugin "airplay_emulation"... Dec 15 15:25:01 volumio volumio[1181]: info: Starting Shairport Sync Dec 15 15:25:01 volumio volumio[1181]: info: Loading plugin "last_100"... Dec 15 15:25:01 volumio volumio[1181]: info: Loading plugin "webradio"... Dec 15 15:25:01 volumio sudo[1278]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:01 volumio volumio[1181]: info: Loading plugin "i2s_dacs"... Dec 15 15:25:01 volumio volumio[1181]: info: I2S DAC not set, start Auto-detection Dec 15 15:25:01 volumio volumio[1181]: info: Loading plugin "volumiodiscovery"... Dec 15 15:25:01 volumio volumio[1181]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 15:25:01 volumio volumio[1181]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 15:25:01 volumio node[1181]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 15:25:01 volumio volumio[1181]: *** WARNING *** For more information see Dec 15 15:25:01 volumio volumio[1181]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 15:25:01 volumio volumio[1181]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 15:25:01 volumio volumio[1181]: *** WARNING *** For more information see Dec 15 15:25:01 volumio node[1181]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 15:25:01 volumio node[1181]: *** WARNING *** For more information see Dec 15 15:25:01 volumio node[1181]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 15:25:01 volumio node[1181]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 15:25:01 volumio node[1181]: *** WARNING *** For more information see Dec 15 15:25:01 volumio volumio[1181]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 15:25:01 volumio volumio[1181]: info: Discovery: Started advertising with name: Volumio Dec 15 15:25:01 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 15:25:01 volumio volumio[1181]: info: Loading plugin "spop"... Dec 15 15:25:05 volumio volumio[1181]: info: Loading plugin "outputs"... Dec 15 15:25:05 volumio volumio[1181]: info: Loading plugin "albumart"... Dec 15 15:25:05 volumio volumio[1181]: info: Plugin example_plugin is not enabled Dec 15 15:25:05 volumio volumio[1181]: info: Loading plugin "inputs"... Dec 15 15:25:05 volumio volumio[1181]: info: Loading plugin "updater_comm"... Dec 15 15:25:05 volumio volumio[1181]: info: Plugin mpdemulation is not enabled Dec 15 15:25:05 volumio volumio[1181]: info: Loading plugin "rest_api"... Dec 15 15:25:05 volumio volumio[1181]: info: Loading plugin "websocket"... Dec 15 15:25:05 volumio volumio[1181]: info: Starting Socket.io Server version 1.7.4 Dec 15 15:25:05 volumio volumio[1181]: info: Loading i18n strings for locale pl Dec 15 15:25:05 volumio volumio[1181]: Updating browse sources language Dec 15 15:25:05 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::initPlayerControls Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: Express server listening on port 3000 Dec 15 15:25:06 volumio volumio[1181]: [Metrics] WebUI: 14s 944.09ms Dec 15 15:25:06 volumio volumio[1181]: info: CoreStateMachine::resetVolumioState Dec 15 15:25:06 volumio volumio[1181]: info: CoreStateMachine::getcurrentVolume Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 15:25:06 volumio volumio[1181]: info: CoreStateMachine::pushState Dec 15 15:25:06 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::volumioPushState Dec 15 15:25:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:06 volumio volumio[1181]: info: Volumio Network Manager: Network status updated: 2 Dec 15 15:25:06 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 1 Dec 15 15:25:06 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.20 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 15:25:07 volumio volumio[1311]: Forking 3 albumart workers Dec 15 15:25:07 volumio volumio[1181]: info: Reloading queue from file Dec 15 15:25:07 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 Dec 15 15:25:07 volumio volumio[1181]: info: Setting Device type: Raspberry PI Dec 15 15:25:07 volumio volumio[1181]: info: CoreStateMachine::setRepeat true single undefined Dec 15 15:25:07 volumio volumio[1181]: info: CoreStateMachine::pushState Dec 15 15:25:07 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:07 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:25:07 volumio volumio[1181]: info: CoreCommandRouter::volumioPushState Dec 15 15:25:07 volumio volumio[1181]: info: CoreStateMachine::setRandom null Dec 15 15:25:07 volumio volumio[1181]: info: CoreStateMachine::pushState Dec 15 15:25:07 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:07 volumio volumio[1181]: info: CoreCommandRouter::volumioPushState Dec 15 15:25:08 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.28 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 15 15:25:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:25:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: Getting this device information Dec 15 15:25:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:08 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:25:08 volumio sudo[1380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 15:25:08 volumio sudo[1380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:08 volumio sudo[1380]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:08 volumio sudo[1382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 15:25:08 volumio sudo[1382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:08 volumio sudo[1382]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: adding 64bfa3e7-46cc-40c3-a7fc-ffdd6b7d2ccb Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: Found device Volumio Dec 15 15:25:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:08 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: this is already registered, 64bfa3e7-46cc-40c3-a7fc-ffdd6b7d2ccb Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: Found device Volumio Dec 15 15:25:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:08 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: adding 0c5a2b39-2654-442a-bbcb-734b28cad9ef Dec 15 15:25:08 volumio volumio[1181]: info: Discovery: Found device Volumio Gosia Dec 15 15:25:09 volumio volumio[1181]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 15 15:25:09 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.20 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Dec 15 15:25:09 volumio volumio[1181]: info: Completed loading Core Plugins Dec 15 15:25:09 volumio volumio[1181]: info: Preparing to generate the ALSA configuration file Dec 15 15:25:09 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 15 15:25:09 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.28 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 15 15:25:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:25:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:25:10 volumio volumio[1181]: info: Discovery: Getting this device information Dec 15 15:25:10 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:10 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:25:10 volumio volumio[1181]: info: Discovery: Connected to remote: 192.168.1.28 Dec 15 15:25:11 volumio volumio[1181]: info: Asound.conf file unchanged, so no further update is needed Dec 15 15:25:11 volumio volumio[1181]: info: Output device has changed, restarting MPD Dec 15 15:25:11 volumio sudo[1386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 15:25:11 volumio sudo[1386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:11 volumio volumio[1181]: info: Output device has changed, restarting Shairport Sync Dec 15 15:25:11 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:11 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:11 volumio sudo[1388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 15:25:11 volumio sudo[1388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:11 volumio sudo[1388]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:11 volumio sudo[1391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 15:25:11 volumio sudo[1391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:11 volumio volumio[1181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 15:25:11 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 15 15:25:11 volumio volumio[1181]: info: ___________ START PLUGINS ___________ Dec 15 15:25:11 volumio volumio[1181]: info: ControllerMpd::onStart: Initializing MPD Dec 15 15:25:11 volumio volumio[1181]: info: Creating MPD Configuration file Dec 15 15:25:11 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:25:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 15:25:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 15:25:11 volumio volumio[1181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 15:25:11 volumio volumio[1181]: info: [1765808711978] CoreMusicLibrary::Adding element Serwery Mediów Dec 15 15:25:11 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:25:12 volumio sudo[1413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 15:25:12 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 15 15:25:12 volumio sudo[1416]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 15:25:12 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 15:25:12 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:25:12 volumio sudo[1416]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:12 volumio sudo[1420]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 15 15:25:12 volumio sudo[1413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:12 volumio sudo[1417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 15:25:12 volumio sudo[1417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:12 volumio volumio[1181]: info: UPNP Browser: Client initialized successfully Dec 15 15:25:12 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:25:12 volumio sudo[1413]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:12 volumio sudo[1386]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:12 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:12 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:12 volumio volumio[1181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 15:25:12 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:12 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:12 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 15 15:25:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 15:25:12 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 15 15:25:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 15:25:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 15:25:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 15:25:12 volumio volumio[1181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 15:25:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 15:25:12 volumio volumio[1181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 15:25:12 volumio volumio[1181]: info: [1765808712984] CoreMusicLibrary::Adding element Last_100 Dec 15 15:25:12 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:25:13 volumio volumio[1181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 15:25:13 volumio volumio[1181]: info: [1765808713034] CoreMusicLibrary::Adding element Webradio Dec 15 15:25:13 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:25:13 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:25:13 volumio sudo[1444]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 15:25:13 volumio sudo[1444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 15:25:13 volumio sudo[1445]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 15 15:25:13 volumio sudo[1444]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:13 volumio volumio[1181]: info: Initializing BBC Radios Dec 15 15:25:13 volumio volumio-remote-updater[646]: [2025-12-15 15:25:13] [connect] Successful connection Dec 15 15:25:13 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:25:13 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:14 volumio volumio[1181]: info: Creating Spotify config file Dec 15 15:25:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:14 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 15 15:25:14 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 15 15:25:14 volumio systemd[1]: setdatetime-helper.service: Consumed 1.078s CPU time. Dec 15 15:25:17 volumio volumio[1181]: info: Volumio Calling Home Dec 15 15:25:19 volumio volumio[1335]: Starting albumart workers Dec 15 15:25:20 volumio volumio[1333]: Starting albumart workers Dec 15 15:25:20 volumio volumio[1332]: Starting albumart workers Dec 15 15:25:20 volumio mpd[1446]: 2025-12-15T15:25:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 15:25:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 15:25:20 volumio sudo[1417]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:20 volumio sudo[1391]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:21 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 15:25:21 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:21 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:21 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.20 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 15 15:25:22 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Dec 15 15:25:22 volumio volumio[1181]: info: Completed starting Core Plugins Dec 15 15:25:22 volumio volumio[1181]: info: ------------------------------------------- Dec 15 15:25:22 volumio volumio[1181]: info: ----- MyVolumio plugins startup ---- Dec 15 15:25:22 volumio volumio[1181]: info: ------------------------------------------- Dec 15 15:25:22 volumio volumio[1181]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 15:25:22 volumio volumio[1181]: info: MPD Permissions set Dec 15 15:25:22 volumio volumio[1181]: info: MPD Permissions set Dec 15 15:25:22 volumio volumio[1181]: info: Upmpdcli Daemon Started Dec 15 15:25:23 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:23 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:23 volumio volumio[1181]: info: MPD running with PID1446 Dec 15 15:25:23 volumio volumio[1181]: ,establishing connection Dec 15 15:25:23 volumio volumio[1181]: info: Volumio called home Dec 15 15:25:23 volumio volumio[1181]: info: Spotify config file written Dec 15 15:25:23 volumio sudo[1507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 15:25:23 volumio sudo[1507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:23 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 15:25:23 volumio 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. Dec 15 15:25:23 volumio 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. Dec 15 15:25:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:23 volumio go-librespot[1510]: go-librespot daemon starting... Dec 15 15:25:23 volumio sudo[1507]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:24 volumio volumio[1181]: info: Listing playlists Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::volumioGetQueue Dec 15 15:25:24 volumio volumio[1181]: info: CoreStateMachine::getQueue Dec 15 15:25:24 volumio volumio[1181]: info: CorePlayQueue::getQueue Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:25:24 volumio go-librespot[1511]: time="2025-12-15T15:25:24+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:25:24 volumio go-librespot[1511]: time="2025-12-15T15:25:24+01:00" level=debug msg="app state loaded" Dec 15 15:25:24 volumio go-librespot[1511]: time="2025-12-15T15:25:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:25:24 volumio volumio[1181]: error: MPD error: The expression evaluated to a falsy value: Dec 15 15:25:24 volumio volumio[1181]: assert.ok(self.idling) Dec 15 15:25:24 volumio volumio[1181]: error: The expression evaluated to a falsy value: Dec 15 15:25:24 volumio volumio[1181]: assert.ok(self.idling) Dec 15 15:25:24 volumio volumio[1181]: error: MPD error: The expression evaluated to a falsy value: Dec 15 15:25:24 volumio volumio[1181]: assert.ok(self.idling) Dec 15 15:25:24 volumio volumio[1181]: error: The expression evaluated to a falsy value: Dec 15 15:25:24 volumio volumio[1181]: assert.ok(self.idling) Dec 15 15:25:24 volumio volumio[1181]: info: No need to fix Spotify hosts Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:24 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=info msg="zeroconf server listening on port 39657" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="obtained new client token: AAA7fA7LxShDV2QIxqIAhxc6KmF9ugjYfpqEPJJvIhX3AdahNwTf5wfuRWUJjUJHzwe7uy2LXkPf1LPq8xGV2PkT49JxvgyS8zOrEhS1xbfCojNwAZsih4v9b+0VUhZTq/o3lGwC0WjhHOr+NKj39aurlpqyN6b53UYzIOu6cavfv1tMOEO72KPNiwtajVMZKIX9gA7NWU7CAK5q5/RnL9SXAoQfQ9CQugxtzognKz7fG3XIb52GW8pMuA==" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="completed keyexchange" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=debug msg="completed challenge" Dec 15 15:25:25 volumio go-librespot[1511]: time="2025-12-15T15:25:25+01:00" level=info msg="authenticated AP" username="ja*****07" Dec 15 15:25:26 volumio volumio[1181]: error: updateQueue error: null Dec 15 15:25:26 volumio sudo[1530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 15:25:26 volumio sudo[1530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:26 volumio sudo[1535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 15:25:26 volumio sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:26 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 15:25:26 volumio mpd_monitor.sh[1540]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 15:25:26 volumio sudo[1530]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:26 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 15:25:26 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 15:25:26 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 15:25:26 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 15:25:26 volumio mpd_monitor.sh[1546]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 15:25:26 volumio sudo[1535]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:26 volumio go-librespot[1511]: time="2025-12-15T15:25:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 15:25:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:25:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:25:26 volumio volumio[1181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 15 15:25:26 volumio volumio[1181]: info: Successfully started MPD Monitor Dec 15 15:25:26 volumio volumio[1181]: info: Successfully started MPD Monitor Dec 15 15:25:26 volumio volumio[1181]: info: Starting Shairport Sync Dec 15 15:25:26 volumio volumio[1181]: info: Starting Shairport Sync Dec 15 15:25:27 volumio sudo[1552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 15:25:27 volumio sudo[1552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:27 volumio volumio[1181]: info: Starting Shairport Sync Dec 15 15:25:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 15:25:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 15:25:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 15:25:27 volumio systemd[1]: shairport-sync.service: Consumed 1.540s CPU time. Dec 15 15:25:27 volumio sudo[1555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 15:25:27 volumio sudo[1555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 15:25:27 volumio sudo[1552]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:27 volumio sudo[1558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 15:25:27 volumio sudo[1558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 15:25:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 15:25:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 15:25:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 15:25:27 volumio sudo[1555]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:27 volumio sudo[1558]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:27 volumio volumio[1181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 15:25:27 volumio volumio[1181]: SPOTIFY: BQCh3or76hXqlpDSK1wXpZMOsnRB6pdxG_BFA5PiH54m2JQqGMwUV1FghBZeWflI0yhoztH_wXE7nKNGiY-viYT8IQJBnfhk8y6-9IgeNITTVzsxT8thqmdypRTxGcbFgqjiSF4m5KPpMHLrEQZliUqddx0An34x4YwDwFxDfmb_AvjIG3WYeX7N600MiDK64LHKoheZDsHi4L-tNTWmypCVl6IF8zm8YKw3FnTMOuk9L1yMnP_zbLk9JbNrl9sOs-hvftrOVZyzv3DuSO_itPdWlS5kx3DwZec Dec 15 15:25:27 volumio volumio[1181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 15:25:27 volumio volumio[1181]: info: New Spotify access token = BQCh3or76hXqlpDSK1wXpZMOsnRB6pdxG_BFA5PiH54m2JQqGMwUV1FghBZeWflI0yhoztH_wXE7nKNGiY-viYT8IQJBnfhk8y6-9IgeNITTVzsxT8thqmdypRTxGcbFgqjiSF4m5KPpMHLrEQZliUqddx0An34x4YwDwFxDfmb_AvjIG3WYeX7N600MiDK64LHKoheZDsHi4L-tNTWmypCVl6IF8zm8YKw3FnTMOuk9L1yMnP_zbLk9JbNrl9sOs-hvftrOVZyzv3DuSO_itPdWlS5kx3DwZec Dec 15 15:25:27 volumio volumio[1181]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 15:25:27 volumio volumio[1181]: info: Shairport-Sync Started Dec 15 15:25:27 volumio volumio[1181]: Error adding Membership: Error: addMembership EINVAL Dec 15 15:25:27 volumio volumio[1181]: info: Shairport-Sync Started Dec 15 15:25:27 volumio volumio[1181]: info: Shairport-Sync Started Dec 15 15:25:28 volumio volumio-remote-updater[646]: [2025-12-15 15:25:28] [connect] Successful connection Dec 15 15:25:28 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:28 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:28 volumio volumio-remote-updater[646]: [2025-12-15 15:25:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808728 101 Dec 15 15:25:28 volumio volumio[1181]: 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: 11 Dec 15 15:25:28 volumio volumio[1181]: SPOTIFY: User informations: {"country":"PL","display_name":"jarekg007","email":"jarekg@data.pl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jarekg007"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/jarekg007","id":"jarekg007","images":[],"product":"premium","type":"user","uri":"spotify:user:jarekg007"} Dec 15 15:25:28 volumio volumio[1181]: info: Spotify Successfully logged in Dec 15 15:25:28 volumio volumio[1181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 15:25:28 volumio volumio[1181]: info: [1765808728862] CoreMusicLibrary::Adding element Spotify Dec 15 15:25:28 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:25:28 volumio volumio[1181]: Cannot find translation for source Spotify Dec 15 15:25:29 volumio volumio[1181]: info: go-librespot daemon successfully initialized Dec 15 15:25:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 15:25:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:29 volumio go-librespot[1604]: go-librespot daemon starting... Dec 15 15:25:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:29 volumio go-librespot[1605]: time="2025-12-15T15:25:29+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:25:29 volumio go-librespot[1605]: time="2025-12-15T15:25:29+01:00" level=debug msg="app state loaded" Dec 15 15:25:29 volumio go-librespot[1605]: time="2025-12-15T15:25:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=info msg="zeroconf server listening on port 36903" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=debug msg="obtained new client token: AACM3RtjACqhwpThiVQFtuWNz1y0ybve+gspDz+NpRk6j3xkM8ZXImhP8+xnV4nOEXS4A3BMcSQm8F6/HE9+JPH0y4/MJHH/vvEl/gXKRJT7HWeyNELjLajpnRYMQWGEsLfaxRXvMRKbUvi7C/KeN8KqbMq6LtKXwTcNcC97+CsLaFJ/fKukfz9/JXvGK++rInpflKiU/6U5QwFC3yd64e61V+e8KsjQInYVzzUTeYBO+/TjYZS2lje8JA==" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Dec 15 15:25:30 volumio go-librespot[1605]: time="2025-12-15T15:25:30+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.1.40:56036->34.158.1.133:80: read: connection reset by peer" Dec 15 15:25:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:25:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:25:32 volumio volumio[1181]: info: Initializing connection to go-librespot Websocket Dec 15 15:25:33 volumio volumio[1181]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:25:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 15:25:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:34 volumio go-librespot[1613]: go-librespot daemon starting... Dec 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+01:00" level=debug msg="app state loaded" Dec 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+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 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+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 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+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 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+01:00" level=info msg="zeroconf server listening on port 44499" Dec 15 15:25:34 volumio go-librespot[1614]: time="2025-12-15T15:25:34+01:00" level=debug msg="obtained new client token: AAAiuvC+BO5KDG5tk7/fs48CUzDCMmDggaNK0uY5ce263de8pxDZCOppPu0v0DOCjGaqvHfiQZ8m474Iyf646G/CUZWBPW/eQD473D6kj2JnBAMnb7IpbJCLKDQU7toyB43mSS1Z+npjUYEXsgQyV/lRHCRxl9Xv7yGPUt6L4M0IEKDRaIP7R7w236eO8XY5r/qqWPMRvKM9I587SHmGikClsMRxzAiedmJssnNjgvS+qHLZFCPBZDlG9g==" Dec 15 15:25:35 volumio go-librespot[1614]: time="2025-12-15T15:25:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:25:35 volumio go-librespot[1614]: time="2025-12-15T15:25:35+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.1.40:55818->34.158.1.133:4070: read: connection reset by peer" Dec 15 15:25:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:25:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 15:25:37 volumio volumio[1181]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 15:25:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 15:25:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:38 volumio go-librespot[1622]: go-librespot daemon starting... Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=debug msg="app state loaded" Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:25:38 volumio go-librespot[1623]: time="2025-12-15T15:25:38+01:00" level=info msg="zeroconf server listening on port 36359" Dec 15 15:25:39 volumio go-librespot[1623]: time="2025-12-15T15:25:39+01:00" level=debug msg="obtained new client token: AAAHz2XLWpPtIQo99fRJxGvRrULIDrGCFv2sdVVloJ4VEHpwOnHzvO2HePUeawou+wk0udcQTAG8I1rPwCd8Gy6ICarIKzQW/fgkTkHxJ2pZLu9NpAT+lhJQ6OmxxmhgdIPlAq6+6tCmDscAbEyXxVyTKFYyokRqm2gPXKv13AKQ9Jl4HGBVtpTaZxfJbCCZNSa7Kv5lipig6KPLlmemNvhuxzALCO3K2tjNiciJIluD5LJ2nW2SvKg=" Dec 15 15:25:39 volumio go-librespot[1623]: time="2025-12-15T15:25:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:25:39 volumio go-librespot[1623]: time="2025-12-15T15:25:39+01:00" level=debug msg="completed keyexchange" Dec 15 15:25:39 volumio go-librespot[1623]: time="2025-12-15T15:25:39+01:00" level=debug msg="completed challenge" Dec 15 15:25:39 volumio go-librespot[1623]: time="2025-12-15T15:25:39+01:00" level=info msg="authenticated AP" username="ja*****07" Dec 15 15:25:44 volumio volumio[1181]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 15:25:44 volumio volumio[1181]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 15:25:44 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:44 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:44 volumio volumio[1181]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 15:25:44 volumio volumio[1181]: info: MyVolumio login type: Token Dec 15 15:25:44 volumio volumio[1181]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 15:25:44 volumio volumio[1181]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 15:25:48 volumio go-librespot[1623]: time="2025-12-15T15:25:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 15:25:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:25:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:25:51 volumio volumio[1181]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 15:25:51 volumio volumio[1181]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 15:25:51 volumio volumio[1181]: info: Streaming services startup Dec 15 15:25:51 volumio volumio[1181]: info: Starting Streaming Daemon Dec 15 15:25:51 volumio volumio[1181]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 15:25:51 volumio sudo[1662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 15:25:51 volumio sudo[1662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:25:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 15:25:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:51 volumio go-librespot[1668]: go-librespot daemon starting... Dec 15 15:25:51 volumio sudo[1662]: pam_unix(sudo:session): session closed for user root Dec 15 15:25:51 volumio go-librespot[1669]: time="2025-12-15T15:25:51+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:25:51 volumio go-librespot[1669]: time="2025-12-15T15:25:51+01:00" level=debug msg="app state loaded" Dec 15 15:25:51 volumio go-librespot[1669]: time="2025-12-15T15:25:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:25:51 volumio volumio[1181]: info: Initializing connection to go-librespot Websocket Dec 15 15:25:51 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:25:51 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:25:51 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25:52+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 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25:52+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 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25:52+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 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25:52+01:00" level=info msg="zeroconf server listening on port 44619" Dec 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25:52+01:00" level=debug msg="obtained new client token: AADJ9jK3hDSd5mlvjkKUgJBDUIk5ZzdtgmTBVyMGj2gf4HzYfPfTwshmlRLph5r3QpkROxbIiy+bpaPcsqN8/P7vauxgRdbz0oJGOC/sH2JiEOhxTJaMRznySvQjSZ9+JCvRazS0LFKECAsl3IGzZeazAPaKvDQ3nQYJjZbekNVTJjBagMuJPh8s1DMxGYbyxodWEuup7A/QU2/qBquCL9ASkoKHI2t/3d/kcJncSGPmE0k7mMEW+3k=" Dec 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:25:52 volumio go-librespot[1669]: time="2025-12-15T15:25: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: read tcp 192.168.1.40:56602->34.158.1.133:4070: read: connection reset by peer" Dec 15 15:25:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:25:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:25:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 15:25:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:25:55 volumio go-librespot[1679]: go-librespot daemon starting... Dec 15 15:25:55 volumio go-librespot[1680]: time="2025-12-15T15:25:55+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:25:55 volumio go-librespot[1680]: time="2025-12-15T15:25:55+01:00" level=debug msg="app state loaded" Dec 15 15:25:55 volumio go-librespot[1680]: time="2025-12-15T15:25:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+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-gae2.spotify.com:80]" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=info msg="zeroconf server listening on port 36373" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=debug msg="obtained new client token: AAA13dVni6b3xcE2tyjm9M58bg3L4vLDoWmTG8UCNBVXuzURngcePZdaHzlybAE69F6RZOBZC53wPrrNB7uDKsjDWVzNFGQmwyY9Id2SKH/SSzfxbiY20eN+hywbMT5qFGGnxQqrMS13ox9FewOaocYMMlRzQvxtPZOiTpuBMG6pgJhxuXrdip+T0iaVb/7TzuIUHAb43fBsg8/yAFB5BTOwtU7SNUJFAd4Xg8i3TuN1q38XJH/UyRQ=" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=debug msg="completed keyexchange" Dec 15 15:25:56 volumio go-librespot[1680]: time="2025-12-15T15:25:56+01:00" level=debug msg="completed challenge" Dec 15 15:25:57 volumio go-librespot[1680]: time="2025-12-15T15:25:57+01:00" level=info msg="authenticated AP" username="ja*****07" Dec 15 15:25:57 volumio go-librespot[1680]: time="2025-12-15T15:25:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 15:25:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:25:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:25:58 volumio volumio[1181]: error: Cannot start Volumio Streaming Daemon Dec 15 15:25:59 volumio volumio[1181]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 15:25:59 volumio volumio[1181]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 15:25:59 volumio volumio[1181]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:25:59 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12 Dec 15 15:25:59 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 13 Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:25:59 volumio volumio[1181]: info: Discovery: Getting this device information Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:59 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:25:59 volumio volumio[1181]: info: Discovery: Getting this device information Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:59 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:25:59 volumio volumio[1181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:25:59 volumio volumio[1181]: info: Discovery: Getting this device information Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:59 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:25:59 volumio volumio[1181]: verbose: New Socket.io Connection to 192.168.1.40:3000 from 192.168.1.25 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 15 Dec 15 15:25:59 volumio volumio[1181]: error: MyVolumio Custom Token format not valid, refreshing it Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 15 15:25:59 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:25:59 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:26:00 volumio volumio-remote-updater[646]: Test mode disabled Dec 15 15:26:00 volumio volumio-remote-updater[646]: Alpha mode disabled Dec 15 15:26:00 volumio volumio-remote-updater[646]: Alpha legacy test mode disabled Dec 15 15:26:00 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 15 15:26:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 15:26:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:26:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:26:00 volumio go-librespot[1703]: go-librespot daemon starting... Dec 15 15:26:00 volumio go-librespot[1704]: time="2025-12-15T15:26:00+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:26:00 volumio go-librespot[1704]: time="2025-12-15T15:26:00+01:00" level=debug msg="app state loaded" Dec 15 15:26:00 volumio go-librespot[1704]: time="2025-12-15T15:26:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:26:00 volumio volumio[1181]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 15 15:26:00 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+01:00" level=info msg="zeroconf server listening on port 43601" Dec 15 15:26:01 volumio volumio[1181]: info: MyVolumio login type: Token Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+01:00" level=debug msg="obtained new client token: AAC0/C+wqiL8sVQPFwH9pa+Akix/kXfuAlvgE/iO/iLbztzoJ3S3rynOYMXUvd8IbHWX5G/fs87qsCBrBxVO4q39oRVeu4Cr25ZFvo3iAMH6sLe/c83paacLWXquEb7sFPZltzOQusvdTjpXOP2byCbz9pf5azPYt5C4cBoSMw6Sl1yZI5iNvsNeXkW9Im52XMUHcSx2a9cLuFtP8WiGCXlrR/ictjbEnTG3CgoomPm62vimKPmeX2Q=" Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:26:01 volumio go-librespot[1704]: time="2025-12-15T15:26:01+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.1.40:56622->34.158.1.133:4070: read: connection reset by peer" Dec 15 15:26:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:26:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:26:02 volumio volumio[1181]: info: Initializing connection to go-librespot Websocket Dec 15 15:26:02 volumio volumio[1181]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 15:26:02 volumio volumio[1181]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 15:26:03 volumio volumio[1181]: info: MyVolumio token set successfully Dec 15 15:26:03 volumio volumio[1181]: info: MYVOLUMIO: Adding device Dec 15 15:26:03 volumio volumio[1181]: info: MYVOLUMIO: Evaluating Server Dec 15 15:26:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 15 15:26:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:26:04 volumio volumio[1181]: info: MyVolumio status changed Dec 15 15:26:04 volumio volumio[1181]: info: Streaming services startup Dec 15 15:26:04 volumio volumio[1181]: info: Starting Streaming Daemon Dec 15 15:26:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:26:04 volumio go-librespot[1731]: go-librespot daemon starting... Dec 15 15:26:04 volumio volumio[1181]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 15:26:04 volumio sudo[1733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 15:26:04 volumio sudo[1733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:26:04 volumio volumio[1181]: info: Removing audio output: Dec 15 15:26:04 volumio volumio[1181]: info: Stoppping Tunnel 1 Dec 15 15:26:04 volumio go-librespot[1734]: time="2025-12-15T15:26:04+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:26:04 volumio go-librespot[1734]: time="2025-12-15T15:26:04+01:00" level=debug msg="app state loaded" Dec 15 15:26:04 volumio go-librespot[1734]: time="2025-12-15T15:26:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:26:04 volumio sudo[1733]: pam_unix(sudo:session): session closed for user root Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:26:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:26:04 volumio sudo[1742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 15:26:04 volumio sudo[1742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:26:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 15:26:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=info msg="zeroconf server listening on port 46879" Dec 15 15:26:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 15:26:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 15:26:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 15:26:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 15:26:05 volumio sudo[1742]: pam_unix(sudo:session): session closed for user root Dec 15 15:26:05 volumio volumio[1181]: info: Setting Geolocation for MyVolumio to eu7 Dec 15 15:26:05 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:05 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:05 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="obtained new client token: AACyQHxtzVjXWkvz5UfC2+uRCKm94/nJg/xDHUBqHL9W+vzs+h0PntH7h924Ai2IMfwA8bcL8AHSKE10kStgjilFwDQIj/LMGywngl3vcjEfH/gLyf4vijXkqy46SwXXJQI3qEr1UY1UV9nXJpGjyK019bNMtHdsZWl4XAbDGjK3xwD2fI8p+cmRIEmF3XwLfcNd0+VbLF/Y+qmMxVKzu75eFwPnUh5g89gSy1uc737VfGTCiYh71Ng=" Dec 15 15:26:05 volumio volumio[1181]: error: Cannot start Volumio Streaming Daemon Dec 15 15:26:05 volumio volumio[1181]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 15:26:05 volumio volumio[1181]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:26:05 volumio volumio[1181]: info: Remote SSH Stopped Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="completed keyexchange" Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="completed challenge" Dec 15 15:26:05 volumio volumio[1181]: info: Initializing connection to go-librespot Websocket Dec 15 15:26:05 volumio go-librespot[1734]: time="2025-12-15T15:26:05+01:00" level=debug msg="new websocket client" Dec 15 15:26:05 volumio volumio[1181]: info: Connection to go-librespot Websocket established Dec 15 15:26:05 volumio volumio[1181]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 15 15:26:06 volumio go-librespot[1734]: time="2025-12-15T15:26:06+01:00" level=info msg="authenticated AP" username="ja*****07" Dec 15 15:26:06 volumio volumio[1181]: info: Updating MyVolumio device info Dec 15 15:26:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:06 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:06 volumio volumio[1181]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 15 15:26:08 volumio volumio[1181]: info: Getting Spotify volume Dec 15 15:26:08 volumio volumio[1181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Dec 15 15:26:09 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 15 15:26:09 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 15 15:26:09 volumio volumio[1181]: info: MYVOLUMIO: Adding device Dec 15 15:26:09 volumio volumio[1181]: info: MYVOLUMIO: Evaluating Server Dec 15 15:26:10 volumio volumio[1181]: info: Setting Geolocation for MyVolumio to eu7 Dec 15 15:26:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:26:11 volumio go-librespot[1734]: time="2025-12-15T15:26:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 15:26:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:26:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:26:11 volumio volumio[1181]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:26:11 volumio volumio[1181]: Error: socket hang up Dec 15 15:26:11 volumio volumio[1181]: at connResetException (node:internal/errors:720:14) Dec 15 15:26:11 volumio volumio[1181]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 15:26:11 volumio volumio[1181]: at Socket.emit (node:events:526:35) Dec 15 15:26:11 volumio volumio[1181]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 15:26:11 volumio volumio[1181]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 15:26:11 volumio volumio[1181]: code: 'ECONNRESET', Dec 15 15:26:11 volumio volumio[1181]: response: undefined Dec 15 15:26:11 volumio volumio[1181]: } Dec 15 15:26:11 volumio volumio[1181]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:26:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 15 15:26:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:26:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 15:26:14 volumio go-librespot[1793]: go-librespot daemon starting... Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=info msg="running go-librespot 0.4.0" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=debug msg="app state loaded" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=info msg="zeroconf server listening on port 36123" Dec 15 15:26:14 volumio go-librespot[1794]: time="2025-12-15T15:26:14+01:00" level=debug msg="obtained new client token: AADWIjGXJxhNI7AIPTzLr2H8af90gD12Ovt5RMQgxkmep/NtEYObii8rKe72b3cDfvUnUQIvc9WeozuNBxevBeRQ/KvRNHi+V3qw0T6k3q9nKCgtRbZRjzGbFVW5eGSfT6UMGo8QEh73rkc2ZS99QRvgusnEbPPAAQNCxG+M1SdCJnwIKuAm8ogq03tynMJmytVh7EClewhngjxYps25c4Q19/7bTV0bwvJPR8HzU2XxT7C75Y4uuOs7fw==" Dec 15 15:26:15 volumio go-librespot[1794]: time="2025-12-15T15:26:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 15 15:26:15 volumio go-librespot[1794]: time="2025-12-15T15:26:15+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.1.40:49794->34.158.1.133:4070: read: connection reset by peer" Dec 15 15:26:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:26:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 15:26:16 volumio sudo[1804]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 15:25' Dec 15 15:26:16 volumio sudo[1804]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"