Nov 01 13:33:00 volumiosalon volumio[935]: info: Loading plugin "volumiodiscovery"... Nov 01 13:33:00 volumiosalon volumio[935]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 13:33:00 volumiosalon volumio[935]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 13:33:00 volumiosalon volumio[935]: *** WARNING *** For more information see Nov 01 13:33:00 volumiosalon volumio[935]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 13:33:00 volumiosalon volumio[935]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 13:33:00 volumiosalon volumio[935]: *** WARNING *** For more information see Nov 01 13:33:00 volumiosalon node[935]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 13:33:00 volumiosalon node[935]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 13:33:00 volumiosalon node[935]: *** WARNING *** For more information see Nov 01 13:33:00 volumiosalon node[935]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 13:33:00 volumiosalon node[935]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 13:33:00 volumiosalon node[935]: *** WARNING *** For more information see Nov 01 13:33:00 volumiosalon volumio[935]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 13:33:00 volumiosalon volumio[935]: info: Discovery: Started advertising with name: VolumioSalon Nov 01 13:33:00 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 13:33:00 volumiosalon volumio[935]: info: Loading plugin "mixcloud"... Nov 01 13:33:01 volumiosalon volumio[935]: info: Loading plugin "soundcloud"... Nov 01 13:33:02 volumiosalon volumio[935]: info: Loading plugin "spop"... Nov 01 13:33:05 volumiosalon volumio[935]: info: Loading plugin "youtube2"... Nov 01 13:33:07 volumiosalon volumio[935]: info: Loading plugin "ytmusic"... Nov 01 13:33:07 volumiosalon volumio-remote-updater[485]: [2025-11-01 13:33:07] [connect] Successful connection Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "outputs"... Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "albumart"... Nov 01 13:33:09 volumiosalon volumio[935]: info: Plugin example_plugin is not enabled Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "inputs"... Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "updater_comm"... Nov 01 13:33:09 volumiosalon volumio[935]: info: Plugin mpdemulation is not enabled Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "rest_api"... Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "websocket"... Nov 01 13:33:09 volumiosalon volumio[935]: info: Starting Socket.io Server version 1.7.4 Nov 01 13:33:09 volumiosalon volumio[935]: info: Loading plugin "80s80s"... Nov 01 13:33:10 volumiosalon volumio[1097]: Forking 3 albumart workers Nov 01 13:33:10 volumiosalon volumio[935]: info: Applying required configuration parameters for plugin 80s80s Nov 01 13:33:11 volumiosalon volumio[935]: info: [1762000391007] [80s80s] API delay: 30 Nov 01 13:33:11 volumiosalon volumio[935]: info: Loading plugin "podcast"... Nov 01 13:33:12 volumiosalon systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Nov 01 13:33:13 volumiosalon volumio[935]: info: ControllerPodcast::constructor Nov 01 13:33:14 volumiosalon systemd[1]: setdatetime-helper.service: Deactivated successfully. Nov 01 13:33:14 volumiosalon systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Nov 01 13:33:14 volumiosalon systemd[1]: setdatetime-helper.service: Consumed 1.932s CPU time. Nov 01 13:33:15 volumiosalon volumio[935]: info: Loading plugin "Systeminfo"... Nov 01 13:33:20 volumiosalon volumio[935]: info: Loading i18n strings for locale fr Nov 01 13:33:20 volumiosalon volumio[935]: Updating browse sources language Nov 01 13:33:20 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:21 volumiosalon volumio[1107]: Starting albumart workers Nov 01 13:33:21 volumiosalon volumio[1108]: Starting albumart workers Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::initPlayerControls Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 13:33:22 volumiosalon volumio[935]: Express server listening on port 3000 Nov 01 13:33:22 volumiosalon volumio[935]: [Metrics] WebUI: 35s 224.60ms Nov 01 13:33:22 volumiosalon volumio[1109]: Starting albumart workers Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreStateMachine::resetVolumioState Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreStateMachine::getcurrentVolume Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreStateMachine::pushState Nov 01 13:33:22 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 13:33:22 volumiosalon volumio[935]: info: CoreCommandRouter::volumioPushState Nov 01 13:33:22 volumiosalon volumio-remote-updater[485]: [2025-11-01 13:33:22] [connect] Successful connection Nov 01 13:33:22 volumiosalon volumio[935]: info: Volumio Network Manager: Network status updated: 1 Nov 01 13:33:23 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Nov 01 13:33:24 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Nov 01 13:33:24 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:24 volumiosalon volumio[935]: info: Reloading queue from file Nov 01 13:33:24 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151:3000 from 192.168.3.105 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreStateMachine::setRepeat null single undefined Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreStateMachine::pushState Nov 01 13:33:24 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreCommandRouter::volumioPushState Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreStateMachine::setRandom true Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreStateMachine::pushState Nov 01 13:33:24 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 13:33:24 volumiosalon volumio[935]: info: CoreCommandRouter::volumioPushState Nov 01 13:33:24 volumiosalon volumio[935]: info: Setting Device type: Raspberry PI Nov 01 13:33:24 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Nov 01 13:33:25 volumiosalon volumio[935]: info: Completed loading Core Plugins Nov 01 13:33:25 volumiosalon volumio[935]: info: Preparing to generate the ALSA configuration file Nov 01 13:33:25 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Nov 01 13:33:25 volumiosalon volumio[935]: info: Discovery: adding 8e36d70c-1812-4fc0-9282-89074ef539a8 Nov 01 13:33:25 volumiosalon volumio[935]: info: Discovery: Found device VolumioSalon Nov 01 13:33:25 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:25 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:26 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151:3000 from 192.168.3.105 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 01 13:33:26 volumiosalon volumio[935]: info: Discovery: this is already registered, 8e36d70c-1812-4fc0-9282-89074ef539a8 Nov 01 13:33:26 volumiosalon volumio[935]: info: Discovery: Found device VolumioSalon Nov 01 13:33:26 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:26 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:26 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Nov 01 13:33:26 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 01 13:33:26 volumiosalon volumio[935]: info: Asound.conf file unchanged, so no further update is needed Nov 01 13:33:26 volumiosalon volumio[935]: info: Output device has changed, restarting MPD Nov 01 13:33:26 volumiosalon volumio[935]: info: Output device has changed, restarting Shairport Sync Nov 01 13:33:26 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:26 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:26 volumiosalon sudo[1205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 13:33:26 volumiosalon sudo[1205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:26 volumiosalon sudo[1205]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:26 volumiosalon sudo[1209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 13:33:26 volumiosalon sudo[1209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:26 volumiosalon volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 13:33:26 volumiosalon volumio[935]: info: ___________ START PLUGINS ___________ Nov 01 13:33:26 volumiosalon volumio[935]: info: ControllerMpd::onStart: Initializing MPD Nov 01 13:33:26 volumiosalon volumio[935]: info: Creating MPD Configuration file Nov 01 13:33:27 volumiosalon systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 01 13:33:27 volumiosalon systemd[1]: Starting mpd.service - Music Player Daemon... Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:27 volumiosalon sudo[1222]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 13:33:27 volumiosalon sudo[1222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:27 volumiosalon volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 13:33:27 volumiosalon sudo[1222]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:27 volumiosalon sudo[1234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 13:33:27 volumiosalon sudo[1234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:27 volumiosalon sudo[1231]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 13:33:27 volumiosalon sudo[1231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 01 13:33:27 volumiosalon sudo[1231]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:27 volumiosalon systemd[1]: mpd.service: Deactivated successfully. Nov 01 13:33:27 volumiosalon systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 01 13:33:27 volumiosalon systemd[1]: mpd.socket: Deactivated successfully. Nov 01 13:33:27 volumiosalon systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 01 13:33:27 volumiosalon systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 01 13:33:27 volumiosalon volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:27 volumiosalon volumio[935]: info: [1762000407653] CoreMusicLibrary::Adding element Last_100 Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:27 volumiosalon systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 01 13:33:27 volumiosalon systemd[1]: Starting mpd.service - Music Player Daemon... Nov 01 13:33:27 volumiosalon volumio[935]: info: [1762000407698] CoreMusicLibrary::Adding element Webradio Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:27 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 13:33:27 volumiosalon volumio[935]: info: Initializing BBC Radios Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:28 volumiosalon sudo[1249]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 13:33:28 volumiosalon sudo[1249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 01 13:33:28 volumiosalon sudo[1263]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Nov 01 13:33:28 volumiosalon sudo[1249]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:28 volumiosalon volumio[935]: info: [1762000408158] CoreMusicLibrary::Adding element Mixcloud Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:28 volumiosalon volumio[935]: Cannot find translation for source Mixcloud Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:28 volumiosalon volumio[935]: info: [1762000408212] CoreMusicLibrary::Adding element SoundCloud Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:28 volumiosalon volumio[935]: Cannot find translation for source Mixcloud Nov 01 13:33:28 volumiosalon volumio[935]: Cannot find translation for source SoundCloud Nov 01 13:33:28 volumiosalon volumio[935]: info: Creating Spotify config file Nov 01 13:33:28 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:29 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:29 volumiosalon volumio[935]: info: [1762000409789] CoreMusicLibrary::Adding element YouTube2 Nov 01 13:33:29 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source Mixcloud Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source SoundCloud Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source YouTube2 Nov 01 13:33:29 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:29 volumiosalon volumio[935]: info: [1762000409961] CoreMusicLibrary::Adding element YouTube Music Nov 01 13:33:29 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source Mixcloud Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source SoundCloud Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source YouTube2 Nov 01 13:33:29 volumiosalon volumio[935]: Cannot find translation for source YouTube Music Nov 01 13:33:30 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:30 volumiosalon volumio[935]: info: [1762000410061] CoreMusicLibrary::Adding element 80s80s Radio Nov 01 13:33:30 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source Mixcloud Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source SoundCloud Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source YouTube2 Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source YouTube Music Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source 80s80s Radio Nov 01 13:33:30 volumiosalon volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 13:33:30 volumiosalon volumio[935]: info: [1762000410184] CoreMusicLibrary::Adding element Podcast Nov 01 13:33:30 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source Mixcloud Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source SoundCloud Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source YouTube2 Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source YouTube Music Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source 80s80s Radio Nov 01 13:33:30 volumiosalon volumio[935]: Cannot find translation for source Podcast Nov 01 13:33:30 volumiosalon volumio[935]: info: Volumio Calling Home Nov 01 13:33:31 volumiosalon volumio[935]: info: Discovery: adding 9080a7df-a081-4c2d-afb5-c9e324a7ab93 Nov 01 13:33:31 volumiosalon volumio[935]: info: Discovery: Found device VolumioComble Nov 01 13:33:31 volumiosalon volumio[935]: info: Discovery: Connecting to remote: 192.168.3.105 Nov 01 13:33:31 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151:3000 from 192.168.3.105 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Nov 01 13:33:31 volumiosalon volumio[935]: info: MPD Permissions set Nov 01 13:33:31 volumiosalon volumio[935]: info: MPD Permissions set Nov 01 13:33:32 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Nov 01 13:33:32 volumiosalon volumio[935]: info: Volumio called home Nov 01 13:33:32 volumiosalon volumio[935]: info: Spotify config file written Nov 01 13:33:32 volumiosalon sudo[1272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 01 13:33:32 volumiosalon sudo[1272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:32 volumiosalon 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. Nov 01 13:33:32 volumiosalon 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. Nov 01 13:33:32 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:32 volumiosalon go-librespot[1274]: go-librespot daemon starting... Nov 01 13:33:32 volumiosalon sudo[1272]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:32 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151:3000 from 192.168.3.105 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:32 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:33:33 volumiosalon volumio[935]: info: No need to fix Spotify hosts Nov 01 13:33:33 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:33+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:33 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:33+01:00" level=debug msg="app state loaded" Nov 01 13:33:33 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=info msg="zeroconf server listening on port 40539" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="obtained new client token: AAAWXZ+5z1vbSR/BgT5RWsyTRjcP04BdfY7fC4gSPiCB22Vi+Zw6kZQBMbk40aQoj5STYVoHVzrOSstZRzQUd6CXIiG+p0C7vaDakZWhhMJs/cvf81RmYqBH2k6FxpMwxsDxjZGLR4YflAuqZ0v0c3w4vsvROnd5IZUXGgXRuHkhdx+qYqDtf6Z8eqWHFbkpnZkS1CPS3pzxkshn+S6d4oVLPMkaN2waKOXkaKurLKg/imo2Vgz+q5fRTmY=" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:34 volumiosalon volumio[935]: info: An error occurred while refreshing Spotify Token Error: Bad Request Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=debug msg="completed challenge" Nov 01 13:33:34 volumiosalon go-librespot[1275]: time="2025-11-01T13:33:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:34 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:34 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:34 volumiosalon volumio[935]: info: Discovery: Connected to remote: 192.168.3.105 Nov 01 13:33:35 volumiosalon volumio[935]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Nov 01 13:33:35 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Nov 01 13:33:35 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151:3000 from 192.168.3.105 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Nov 01 13:33:35 volumiosalon volumio[935]: info: Starting Shairport Sync Nov 01 13:33:35 volumiosalon volumio[935]: info: Starting Shairport Sync Nov 01 13:33:35 volumiosalon volumio[935]: info: Starting Shairport Sync Nov 01 13:33:35 volumiosalon sudo[1295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 13:33:35 volumiosalon sudo[1295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:35 volumiosalon sudo[1297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 13:33:35 volumiosalon sudo[1297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:35 volumiosalon volumio[935]: verbose: New Socket.io Connection to 192.168.3.151 from 192.168.3.140 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 16 Nov 01 13:33:35 volumiosalon systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 01 13:33:35 volumiosalon systemd[1]: shairport-sync.service: Deactivated successfully. Nov 01 13:33:35 volumiosalon sudo[1300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 13:33:35 volumiosalon systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 13:33:35 volumiosalon systemd[1]: shairport-sync.service: Consumed 2.852s CPU time. Nov 01 13:33:35 volumiosalon sudo[1300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:35 volumiosalon systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 13:33:35 volumiosalon sudo[1295]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:36 volumiosalon systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 01 13:33:36 volumiosalon systemd[1]: shairport-sync.service: Deactivated successfully. Nov 01 13:33:36 volumiosalon systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 13:33:36 volumiosalon systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 13:33:36 volumiosalon sudo[1297]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:36 volumiosalon systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 01 13:33:36 volumiosalon systemd[1]: shairport-sync.service: Deactivated successfully. Nov 01 13:33:36 volumiosalon systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 13:33:36 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 13:33:36 volumiosalon systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 13:33:36 volumiosalon sudo[1300]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:36 volumiosalon volumio[935]: info: Shairport-Sync Started Nov 01 13:33:36 volumiosalon volumio[935]: Error adding Membership: Error: addMembership EINVAL Nov 01 13:33:36 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetVisibleSources Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:37 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:37 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 01 13:33:37 volumiosalon volumio[935]: info: Received Get System Info Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 13:33:37 volumiosalon volumio[935]: info: Discovery: Getting this device information Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:37 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:37 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:37 volumiosalon volumio[935]: info: Listing playlists Nov 01 13:33:37 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Nov 01 13:33:37 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetQueue Nov 01 13:33:37 volumiosalon go-librespot[1343]: go-librespot daemon starting... Nov 01 13:33:37 volumiosalon volumio-remote-updater[485]: [2025-11-01 13:33:37] [connect] Successful connection Nov 01 13:33:37 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:37 volumiosalon volumio[935]: info: CoreStateMachine::getQueue Nov 01 13:33:37 volumiosalon volumio[935]: info: CorePlayQueue::getQueue Nov 01 13:33:37 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:37+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:37 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:37+01:00" level=debug msg="app state loaded" Nov 01 13:33:37 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+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-gew4.spotify.com:80]" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=info msg="zeroconf server listening on port 32943" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=debug msg="obtained new client token: AABzU6Ek7jWEXDy1taSZLIWnbhFFS1y/lCyCIDR28BqKIdXqDzpKZ5dHmZzl6qBfnrYPBUECjIH5eS+vRNaDxLJSscFK5WlmrEd/MpICMEHA0NLHJeBQUdJYEHtWBj+8PLR84ygaKVr3G1VlPNrCIN04AkQIwgIXH13qKMHs0gynLDmXVF/csmO+u3dQH96yeN03iD8nMF/GOeE6lOiCdHaB4g/B72SJDKEEAVJ58qzpzYGB0Y50dKWx" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=debug msg="completed challenge" Nov 01 13:33:38 volumiosalon go-librespot[1344]: time="2025-11-01T13:33:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:38 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:38 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:39 volumiosalon volumio[935]: info: Shairport-Sync Started Nov 01 13:33:39 volumiosalon volumio[935]: info: Shairport-Sync Started Nov 01 13:33:39 volumiosalon volumio[935]: info: go-librespot daemon successfully initialized Nov 01 13:33:39 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Nov 01 13:33:39 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:39 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:40 volumiosalon mpd[1264]: 2025-11-01T13:33:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 13:33:40 volumiosalon systemd[1]: Started mpd.service - Music Player Daemon. Nov 01 13:33:40 volumiosalon sudo[1234]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:40 volumiosalon sudo[1209]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:41 volumiosalon volumio-remote-updater[485]: [2025-11-01 13:33:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1762000417 101 Nov 01 13:33:41 volumiosalon volumio[935]: 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: 17 Nov 01 13:33:41 volumiosalon volumio[935]: info: Completed starting Core Plugins Nov 01 13:33:41 volumiosalon volumio[935]: info: ------------------------------------------- Nov 01 13:33:41 volumiosalon volumio[935]: info: ----- MyVolumio plugins startup ---- Nov 01 13:33:41 volumiosalon volumio[935]: info: ------------------------------------------- Nov 01 13:33:41 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 01 13:33:41 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Nov 01 13:33:41 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:42 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:42 volumiosalon go-librespot[1359]: go-librespot daemon starting... Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="app state loaded" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:42 volumiosalon volumio[935]: error: MPD error: The expression evaluated to a falsy value: Nov 01 13:33:42 volumiosalon volumio[935]: assert.ok(self.idling) Nov 01 13:33:42 volumiosalon volumio[935]: error: The expression evaluated to a falsy value: Nov 01 13:33:42 volumiosalon volumio[935]: assert.ok(self.idling) Nov 01 13:33:42 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:33:42 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:33:42 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=info msg="zeroconf server listening on port 39337" Nov 01 13:33:42 volumiosalon volumio[935]: error: updateQueue error: null Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="obtained new client token: AAD3t/QT6KjWwhcve2D/xLqUDbkmZG9+HIQxCqub+QWr8VYvRTJbOaWF6amfjMbZ+dqF0y7N9+7kNmqDyopwtTaii5nNL5Vq3JXfIu8b7zNCIFzE6LdwRfMjs4iOOJFs5YV2maUsvKijADERrqAxW9a6DlM9fG/AG+RGLpBa2Yipx/+QLCfQT7WPAupiWKKX9R1usLvELWaWrk8osVJGl1NDBCpgT3g6rJ6vAa8m3LBY+zHn4E/vvXTy" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=debug msg="completed challenge" Nov 01 13:33:42 volumiosalon go-librespot[1360]: time="2025-11-01T13:33:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:42 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:42 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:42 volumiosalon volumio[935]: info: MPD running with PID1264 Nov 01 13:33:42 volumiosalon volumio[935]: ,establishing connection Nov 01 13:33:43 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: socket hang up Nov 01 13:33:43 volumiosalon volumio[935]: error: updateQueue error: null Nov 01 13:33:44 volumiosalon sudo[1369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 01 13:33:44 volumiosalon sudo[1369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:44 volumiosalon sudo[1371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 01 13:33:44 volumiosalon sudo[1371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:45 volumiosalon systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 01 13:33:45 volumiosalon sudo[1369]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:45 volumiosalon mpd_monitor.sh[1374]: MPD Monitor Service: Starting MPD Monitor Service Nov 01 13:33:45 volumiosalon volumio[935]: info: Successfully started MPD Monitor Nov 01 13:33:45 volumiosalon sudo[1371]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:45 volumiosalon volumio[935]: info: Successfully started MPD Monitor Nov 01 13:33:45 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Nov 01 13:33:45 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:46 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:33:46 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:33:46 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:46 volumiosalon go-librespot[1378]: go-librespot daemon starting... Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=debug msg="app state loaded" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+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]" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=info msg="zeroconf server listening on port 37493" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=debug msg="obtained new client token: AABiirry4IMEc19nSLR7xKFwr/YUnQ2bez7W/uS/wAQcuTwytGHNvFXcu/3eO7vPMYaXZ02WySsFPm0N0JN5SwRGOktrTCyj6JpByjRdc0zDRvVyYuHBMz1m6gejpnbNbQ/EYD8YjsrpraQBEBhKSxJsKnwIabNrV14xXTVERu/u0Bi0latfe3Fy3WxAC7+lSADa1fn8mneLyCjST9CgBySx1FN5tDi19eT+ZCYUbJfDEOQdZy0TShWP" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=debug msg="completed challenge" Nov 01 13:33:46 volumiosalon go-librespot[1379]: time="2025-11-01T13:33:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:46 volumiosalon volumio[935]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 01 13:33:46 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:46 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:49 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:33:49 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:33:50 volumiosalon ntpd[784]: CLOCK: time stepped by 0.418912 Nov 01 13:33:50 volumiosalon ntpd[784]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Nov 01 13:33:50 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Nov 01 13:33:50 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:50 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:50 volumiosalon go-librespot[1400]: go-librespot daemon starting... Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=debug msg="app state loaded" Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:33:50 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:50+01:00" level=info msg="zeroconf server listening on port 42765" Nov 01 13:33:50 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 01 13:33:50 volumiosalon volumio[935]: info: Adding plugin bluetooth to MyMusic Plugins Nov 01 13:33:50 volumiosalon volumio[935]: info: Adding plugin multiroom to MyMusic Plugins Nov 01 13:33:50 volumiosalon volumio[935]: info: Adding plugin metavolumio to MyMusic Plugins Nov 01 13:33:51 volumiosalon volumio[935]: info: Adding plugin cd_controller to MyMusic Plugins Nov 01 13:33:51 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:51+01:00" level=debug msg="obtained new client token: AACLDOPz870TEH6AHsN8H8j3LcL1vCxeaD9e/k/5SrcbWBsr2dlKSN6egbgPHd9hyTlI2ABv0BO8s+zi5jq8J1I54HOqX9Xsv44GX+pYUn2GvkosPtKqhiNRVqOlZC9XVzDmAICbT7lawKlgi1cgO/wMIKNyMitet3IfS37m561y8Fke0yUzRJlieEumbVpg2LhBDQsWVe6ZffjxKVJT+eePf4X2PTaw4LEh+Z9lOVnzNwptcctWaiv6" Nov 01 13:33:51 volumiosalon volumio[935]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 01 13:33:51 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:51+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:51 volumiosalon volumio[935]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 01 13:33:51 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:51+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:51 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:51+01:00" level=debug msg="completed challenge" Nov 01 13:33:51 volumiosalon volumio[935]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 01 13:33:51 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 01 13:33:51 volumiosalon go-librespot[1401]: time="2025-11-01T13:33:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:51 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:51 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:54 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Nov 01 13:33:54 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:54 volumiosalon volumio[935]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 01 13:33:54 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 01 13:33:54 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:54 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:33:54 volumiosalon volumio[935]: info: Starting MyVolumio Remote Streaming Endpoints Nov 01 13:33:54 volumiosalon volumio[935]: info: MyVolumio login type: Token Nov 01 13:33:54 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:54 volumiosalon go-librespot[1409]: go-librespot daemon starting... Nov 01 13:33:54 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:54+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:54 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:54+01:00" level=debug msg="app state loaded" Nov 01 13:33:54 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:54 volumiosalon volumio[935]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 01 13:33:54 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+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]" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+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]" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=info msg="zeroconf server listening on port 39507" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=debug msg="obtained new client token: AABK1LfBWvPbet2ARfBX0QHWcX6iQRqukqeSXhFvpITffTwKCzlVf6G9QYmcaCa5br9SNqtjBS4oTZp61Zv7VmQ58dFwly6JdVclEF+a032fOxBCMImhwq/IxEK4y7dJkzDT56u49kPD+AN92Pko7BUlqqTHQligC3RPhy4AsSxQw9ZbKM+UgtSNvnqzc0Wlelg0zbZjnu0vH2Hu/1EqskjmUbtPKU629iQw4IPtzTpIkFutplCMqwT/" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=debug msg="completed challenge" Nov 01 13:33:55 volumiosalon go-librespot[1410]: time="2025-11-01T13:33:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:55 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:55 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:58 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Nov 01 13:33:58 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:58 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:33:58 volumiosalon go-librespot[1431]: go-librespot daemon starting... Nov 01 13:33:58 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:58+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:33:58 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:58+01:00" level=debug msg="app state loaded" Nov 01 13:33:58 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:33:59 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33: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-gew4.spotify.com:80]" Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 13:33:59 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=info msg="zeroconf server listening on port 34013" Nov 01 13:33:59 volumiosalon volumio[935]: info: Streaming services startup Nov 01 13:33:59 volumiosalon volumio[935]: info: Starting Streaming Daemon Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=debug msg="obtained new client token: AAB4ROuZ9pfxXhDNXnMU7BSaHTWGbU78cDoXrAdqa4+HQBkXXjKayfpzzU0MZNdRyhvio2s5/JpfewgGplBRg1vPfXV8xaH6sRjC+yQQp0GsUGciQChB+f4BX1mWW8/2Zs9DcA05thgjCZI1F0PoEr9Fc6PTwIbKlKbJGUH/mzu6Bykdgr1MW2gc9wzD8TkGseL5GQRGUdonIpD73WhNDxULuNzBvXduh2qLMPwPZsvz+66PHz61rCE2" Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=debug msg="completed keyexchange" Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=debug msg="completed challenge" Nov 01 13:33:59 volumiosalon go-librespot[1432]: time="2025-11-01T13:33:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:33:59 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:33:59 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:33:59 volumiosalon volumio[935]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 01 13:33:59 volumiosalon sudo[1441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 13:33:59 volumiosalon sudo[1441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:33:59 volumiosalon sudo[1441]: pam_unix(sudo:session): session closed for user root Nov 01 13:33:59 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:33:59 volumiosalon volumio[935]: error: Cannot start Volumio Streaming Daemon Nov 01 13:33:59 volumiosalon volumio[935]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 13:33:59 volumiosalon volumio[935]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 13:34:00 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:00 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 13:34:00 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:00 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 13:34:01 volumiosalon volumio[935]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 01 13:34:02 volumiosalon volumio-remote-updater[485]: Test mode enabled Nov 01 13:34:02 volumiosalon volumio-remote-updater[485]: Alpha mode disabled Nov 01 13:34:02 volumiosalon volumio-remote-updater[485]: Alpha legacy test mode disabled Nov 01 13:34:02 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 01 13:34:02 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Nov 01 13:34:02 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:02 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:02 volumiosalon go-librespot[1451]: go-librespot daemon starting... Nov 01 13:34:02 volumiosalon volumio[935]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=debug msg="app state loaded" Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:02 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:34:02 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:02+01:00" level=info msg="zeroconf server listening on port 45367" Nov 01 13:34:03 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:03+01:00" level=debug msg="obtained new client token: AADw4/b5rrbnBVPKNK6xT9J3hCF9UgfWBwRdQ124n0RERdHuQEhAopismRKWiOA0Ap/fLCNSGJdDaSrwSGu6fZGPKfvLenNbc9EENZPzI3Gh2N7WLAF2+OnDovJ+x0pj3T78xR+3pf9rfYpbtHQeF5/hDjvLDTsEylNu6aes83Qkj3SfQE6IX3VLXAf+6os4T7dShBP0BxblcwWb35U9UGghGo83DuD9yMT6DiRlqlg7qANnlxKyvEd8" Nov 01 13:34:03 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:03+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:03 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:03+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:03 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:03+01:00" level=debug msg="completed challenge" Nov 01 13:34:03 volumiosalon go-librespot[1452]: time="2025-11-01T13:34:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:03 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:03 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:03 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:03 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:03 volumiosalon volumio[935]: info: MyVolumio token set successfully Nov 01 13:34:03 volumiosalon volumio[935]: info: MYVOLUMIO: Adding device Nov 01 13:34:03 volumiosalon volumio[935]: info: MYVOLUMIO: Evaluating Server Nov 01 13:34:04 volumiosalon volumio[935]: info: MyVolumio status changed Nov 01 13:34:04 volumiosalon volumio[935]: info: Streaming services startup Nov 01 13:34:04 volumiosalon volumio[935]: info: Starting Streaming Daemon Nov 01 13:34:04 volumiosalon volumio[935]: info: Removing browser output: myVolumio user plan is not superstar Nov 01 13:34:04 volumiosalon volumio[935]: info: Removing audio output: Nov 01 13:34:04 volumiosalon volumio[935]: info: Stoppping Tunnel 1 Nov 01 13:34:04 volumiosalon sudo[1478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 13:34:04 volumiosalon sudo[1478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:34:04 volumiosalon sudo[1478]: pam_unix(sudo:session): session closed for user root Nov 01 13:34:04 volumiosalon sudo[1480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 01 13:34:04 volumiosalon sudo[1480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 13:34:04 volumiosalon volumio[935]: error: Cannot start Volumio Streaming Daemon Nov 01 13:34:04 volumiosalon volumio[935]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 13:34:04 volumiosalon volumio[935]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon 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. Nov 01 13:34:04 volumiosalon sudo[1480]: pam_unix(sudo:session): session closed for user root Nov 01 13:34:05 volumiosalon volumio[935]: info: Remote SSH Stopped Nov 01 13:34:06 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:06 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:06 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Nov 01 13:34:06 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:06 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:06 volumiosalon go-librespot[1486]: go-librespot daemon starting... Nov 01 13:34:06 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:06+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:06 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:06+01:00" level=debug msg="app state loaded" Nov 01 13:34:06 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=info msg="zeroconf server listening on port 45539" Nov 01 13:34:07 volumiosalon volumio[935]: info: Setting Geolocation for MyVolumio to eu6 Nov 01 13:34:07 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:07 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:07 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="obtained new client token: AAAfxWEKOquN2HMz/Opi8WnnyHbjsWNr3TGX2Aa1ZPzxDrZ/H26MiK8dzx5QGRSwkJcmUk+r4A7B2Id3J/3MIuB/un9UfbmWI+JschXn2wHidxtc1Ua9TD57ymb1yAb8YStcgn9bUrj3bRu+EZGKrpDWKgaV6HJmlvLsilLK7OLJ1xPft2W3ws0ut2WrUB0FCLYF2t6Z3jezZQy3ozUAPu9guP8PlP2DUbeaGBOQmpsj6cBeYAo+7J++" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=debug msg="completed challenge" Nov 01 13:34:07 volumiosalon go-librespot[1487]: time="2025-11-01T13:34:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:07 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:07 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:08 volumiosalon volumio[935]: info: Successfully Added MyVolumio device Nov 01 13:34:08 volumiosalon volumio[935]: info: Updating MyVolumio device info Nov 01 13:34:08 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:08 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:08 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:08 volumiosalon volumio[935]: info: Successfully Updated MyVolumio device Nov 01 13:34:09 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:09 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:09 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 13:34:09 volumiosalon volumio[935]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Nov 01 13:34:09 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetState Nov 01 13:34:09 volumiosalon volumio[935]: info: CorePlayQueue::getTrack 0 Nov 01 13:34:10 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Nov 01 13:34:10 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:10 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:10 volumiosalon go-librespot[1509]: go-librespot daemon starting... Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+01:00" level=debug msg="app state loaded" Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+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]" Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+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]" Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+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]" Nov 01 13:34:10 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:10+01:00" level=info msg="zeroconf server listening on port 37947" Nov 01 13:34:11 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:11+01:00" level=debug msg="obtained new client token: AADk1WXcYWCeKoSKav2/ZCjPczbRzrT76jmegRa1ld/cHW/lNJJEmaYoXCJYfYbEF3CZVd7Yupae5T5h1Z2+y1TS1lf2jvwRvUhxhtmo3NfPOWrQfAbKdfjhY6vGVNofsxKInziiKZimz2mRX3Ayj/sPOVQ+O0dIZkSZF4iFlxXR0pu66YivaryOxYtxuUibZ4v4FjOHcCCOgEgKlhv2QRvNFn0gaAfOuvwWpngoTr40aJsGrU1AWyET" Nov 01 13:34:11 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:11+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:11 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:11+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:11 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:11+01:00" level=debug msg="completed challenge" Nov 01 13:34:11 volumiosalon go-librespot[1510]: time="2025-11-01T13:34:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:11 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:11 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:12 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:12 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:14 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Nov 01 13:34:14 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 01 13:34:14 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::volumioGetBrowseSources Nov 01 13:34:14 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 13:34:14 volumiosalon go-librespot[1517]: go-librespot daemon starting... Nov 01 13:34:14 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:14+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:14 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:14+01:00" level=debug msg="app state loaded" Nov 01 13:34:14 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=info msg="zeroconf server listening on port 37617" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="obtained new client token: AADOpCYiVYbXB42XnZ+EM2jXG1BdiOQZ6LA9497BP+ghx+mryzqaRgzQZuWgDvwSGP+liSl9drs0POUIqCoeDJ1vPIPr2E+1OIoYaV1PCgcaw5MJl9HB36spz9z0RFEiQfdEpyebwMRn55KHahLmOLPWjT1X/C1Tyh2R0PgExV/QheE3YBqHBeG5GVqzLFuvufVSEJHaeLwnoMaSnj5Z05AO5m4HiavnKrOeqRnaXpFzWs6w2x/Meu29" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=debug msg="completed challenge" Nov 01 13:34:15 volumiosalon go-librespot[1518]: time="2025-11-01T13:34:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:15 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:15 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:15 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:15 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:18 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Nov 01 13:34:18 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:18 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:18 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:18 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:18 volumiosalon go-librespot[1540]: go-librespot daemon starting... Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=debug msg="app state loaded" Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:34:18 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:18+01:00" level=info msg="zeroconf server listening on port 43321" Nov 01 13:34:19 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:19+01:00" level=debug msg="obtained new client token: AAAvBDfHLUFvL+LlXsnhvD+AXRiU7SRmBWRNRzgKOPW2oyQ6lgwVf45WunzQtEox0TbckKRNNNzOd2H2fOSy6I7ZevtGWSHlry6uojIBOJ/nwNB7aAOZTN1XTD6x2Zu1yfjrY4IsynN18UXPAB8pRK59sOe8Kr6C22qbKjv/HOMCnmFAOigqBsf4jZXlEOv+GYK977fn0N3tziMh+O6c6S4OOiZzQeSRKVCfcIK8llyFKlxihektuFjD" Nov 01 13:34:19 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:19+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:19 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:19+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:19 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:19+01:00" level=debug msg="completed challenge" Nov 01 13:34:19 volumiosalon go-librespot[1541]: time="2025-11-01T13:34:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:19 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:19 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:19 volumiosalon volumio[935]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 01 13:34:19 volumiosalon volumio[935]: info: Completed starting MyVolumio Plugin Nov 01 13:34:19 volumiosalon volumio[935]: [Metrics] CommandRouter: 90s 469.33ms Nov 01 13:34:19 volumiosalon volumio[935]: info: CoreCommandRouter::volumiosetStartupVolume Nov 01 13:34:19 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 13:34:19 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 13:34:19 volumiosalon volumio[935]: info: CoreCommandRouter::Close All Modals sent Nov 01 13:34:19 volumiosalon volumio[935]: info: CoreCommandRouter::Close All Modals sent Nov 01 13:34:20 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 01 13:34:20 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 01 13:34:20 volumiosalon volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 01 13:34:21 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:21 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:22 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Nov 01 13:34:22 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:22 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:22 volumiosalon go-librespot[1551]: go-librespot daemon starting... Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=debug msg="app state loaded" Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:34:22 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:22+01:00" level=info msg="zeroconf server listening on port 35211" Nov 01 13:34:23 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:23+01:00" level=debug msg="obtained new client token: AAC+qGEQansgOsMosXfbAq8o3GSOi1EoKo8nSYEQ2S+Qrf6D8sli/w8ujYDt3L3wgQHuvHv+bAK6mQ65bS71cDd2cft649sVJDEVRch2ANxvTfexkWwff3lWweqOOg2/oHf5bWgcmWLiKjK8vb7KD2VNizBcDPm22NM/Hgs2HT16kgMkdCLOYOfctEuGEFepgrKH9vyXCQsf6pv/ZLgREbiQI0x/UxAXISuygJKv9+oVq/6iyflSIr/f" Nov 01 13:34:23 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:23+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:23 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:23+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:23 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:23+01:00" level=debug msg="completed challenge" Nov 01 13:34:23 volumiosalon go-librespot[1552]: time="2025-11-01T13:34:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:23 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:23 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:24 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:24 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:26 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Nov 01 13:34:26 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:26 volumiosalon volumio[935]: info: BOOT COMPLETED Nov 01 13:34:26 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:26 volumiosalon go-librespot[1562]: go-librespot daemon starting... Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+01:00" level=debug msg="app state loaded" Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+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]" Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+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]" Nov 01 13:34:26 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:26+01:00" level=info msg="zeroconf server listening on port 46769" Nov 01 13:34:27 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:27+01:00" level=debug msg="obtained new client token: AAAZ1Eg1w1kffe7FAqSj+ERk3sSEPyJNdJjG9ZLY419cyAbamdzvI/h5ECbFt3yD4Ekoh9MUGuq2xFjFQzv+1vrzbbT1i4/jnIwZiMpdxfka2eU9pcPHYJJ622+GskBAZQNNs4Y7d5sqlRcw0v0v4pmmonEHrJRqMPJb7JKEadtsJmRsZXTiRQSimOW+wZ0EHqA4GS+5i3Kj0DQCGk62exF59klCo4/NS0B1wTFPRypMSkP1gsx3PLIq" Nov 01 13:34:27 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:27+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:27 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:27+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:27 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:27+01:00" level=debug msg="completed challenge" Nov 01 13:34:27 volumiosalon go-librespot[1563]: time="2025-11-01T13:34:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:27 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:27 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:27 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:27 volumiosalon volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:30 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Nov 01 13:34:30 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:30 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:30 volumiosalon go-librespot[1584]: go-librespot daemon starting... Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=debug msg="app state loaded" Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:30 volumiosalon volumio[935]: info: Initializing connection to go-librespot Websocket Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=debug msg="new websocket client" Nov 01 13:34:30 volumiosalon volumio[935]: info: Connection to go-librespot Websocket established Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 01 13:34:30 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:30+01:00" level=info msg="zeroconf server listening on port 39645" Nov 01 13:34:31 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:31+01:00" level=debug msg="obtained new client token: AAB5XYr22SLU+yBXhq4g1If518z2BygoruudIfy6mfIwiiUFGApOgMHpiOAHClDe3+BcZgNaKkg+azmKJOcXPiuPcZWd79H4mGTfhjLVEEbOl/B5Ojz98rNeqodlxST6/TzEeS18aNiTmO0tOL+DdYj/gNIU4yumF1c4iZkDVBVGWcGeVs6I5pxpCk8BCpZgRCziwLM8DuUPN5bnAEt5GM1aYgTCCybrGj9xPxyfFWrYd/dC7Uopa0np" Nov 01 13:34:31 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:31+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:31 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:31+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:31 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:31+01:00" level=debug msg="completed challenge" Nov 01 13:34:31 volumiosalon go-librespot[1585]: time="2025-11-01T13:34:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:31 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:31 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:31 volumiosalon volumio[935]: info: Connection to go-librespot Websocket closed Nov 01 13:34:33 volumiosalon volumio[935]: info: Getting Spotify volume Nov 01 13:34:33 volumiosalon volumio[935]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 13:34:34 volumiosalon volumio[935]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 13:34:34 volumiosalon volumio[935]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 01 13:34:34 volumiosalon volumio[935]: errno: -111, Nov 01 13:34:34 volumiosalon volumio[935]: code: 'ECONNREFUSED', Nov 01 13:34:34 volumiosalon volumio[935]: syscall: 'connect', Nov 01 13:34:34 volumiosalon volumio[935]: address: '127.0.0.1', Nov 01 13:34:34 volumiosalon volumio[935]: port: 9879, Nov 01 13:34:34 volumiosalon volumio[935]: response: undefined Nov 01 13:34:34 volumiosalon volumio[935]: } Nov 01 13:34:34 volumiosalon volumio[935]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 13:34:34 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Nov 01 13:34:34 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:34 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:34 volumiosalon go-librespot[1604]: go-librespot daemon starting... Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+01:00" level=debug msg="app state loaded" Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+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]" Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+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]" Nov 01 13:34:34 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:34+01:00" level=info msg="zeroconf server listening on port 36715" Nov 01 13:34:35 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:35+01:00" level=debug msg="obtained new client token: AADBU1q2c3Ty9M9ziSlaKi0GcXZP3Edmpo4QeIrpwd/0n312qWDCJLLs4xRn39Z33/GYnPtX6gmRJC9C4p6bcdphvaC5CxpXB/IPhjDS9LutMPtR+I2LAkCRjAU1VeY1PGWAkhiBIJU2KpBDqEXktPJZ3C7DLDiT2gd1nRUNCMym4/EklPkCFjFay0HPqOBk7KoMMMDZLoT5JGGzo0VLwIrrN1S1aV3DGQRiP8rJgJp9b+dfL5fKxGhU" Nov 01 13:34:35 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:35+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:35 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:35+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:35 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:35+01:00" level=debug msg="completed challenge" Nov 01 13:34:35 volumiosalon go-librespot[1605]: time="2025-11-01T13:34:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:35 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:35 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:38 volumiosalon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Nov 01 13:34:38 volumiosalon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:38 volumiosalon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 13:34:38 volumiosalon go-librespot[1628]: go-librespot daemon starting... Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+01:00" level=info msg="running go-librespot 0.4.0" Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+01:00" level=debug msg="app state loaded" Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+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-gew4.spotify.com:80]" Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 01 13:34:38 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:38+01:00" level=info msg="zeroconf server listening on port 39731" Nov 01 13:34:39 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:39+01:00" level=debug msg="obtained new client token: AABqjirGZDlmn+bX0mvsp5pRrmKghcYet1EcyCCiJJg920vjtLTBz1vE58Nk7AkQKSVtpDtE0qxSfAp6d6AVXOExVldMspKa8GlOHPz7+omVhzhDsB6sy8UORbfb6SgLulsJczYd0cWTSLEgH7j82NpZewMkhdWreNTXp2zPYmbl+Vam8RsoQY940nTzq6eoJ6YHwL0figpAQ2XVXnpGqpjMSh2161+Xr91+PeUOYq0EUEevKPm+djp7" Nov 01 13:34:39 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:39+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 13:34:39 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:39+01:00" level=debug msg="completed keyexchange" Nov 01 13:34:39 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:39+01:00" level=debug msg="completed challenge" Nov 01 13:34:39 volumiosalon go-librespot[1629]: time="2025-11-01T13:34:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Nov 01 13:34:39 volumiosalon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 13:34:39 volumiosalon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 13:34:40 volumiosalon sudo[1638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-01 13:33' Nov 01 13:34:40 volumiosalon sudo[1638]: 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="5ef3d56f987d109f3e21bfa246dbbb723cf6a917" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="c7bff9654d2984a81c5720476c2c8ac531869c54" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Oct 9 18:08:11 UTC 2025" VOLUMIO_VERSION="4.062" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="00524295c246b7d72f125e4c54b86a88"