Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "network"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Refreshing Cached IP Addresses Feb 07 19:15:00 volumio-stefan sudo[5140]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 19:15:00 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:00+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:00 volumio-stefan sudo[5140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:00 volumio-stefan sudo[5140]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:00 volumio-stefan sudo[5142]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 19:15:00 volumio-stefan sudo[5142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "services"... Feb 07 19:15:00 volumio-stefan sudo[5142]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "alsa_controller"... Feb 07 19:15:00 volumio-stefan sudo[5149]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 19:15:00 volumio-stefan sudo[5149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:00 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:00 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "wizard"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "networkfs"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Starting Udev Watcher for removable devices Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Ignoring mount for partition: boot Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Ignoring mount for partition: volumio Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Ignoring mount for partition: volumio_data Feb 07 19:15:00 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "volumio_command_line_client"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Plugin upnp is not enabled Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "my_music"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "mpd"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Plugin upnp_browser is not enabled Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "alarm-clock"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Plugin airplay_emulation is not enabled Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "last_100"... Feb 07 19:15:00 volumio-stefan volumio[5101]: info: Loading plugin "webradio"... Feb 07 19:15:00 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:00+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 19:15:01 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:01+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 19:15:01 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:01+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:01 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:01+02:00" level=debug msg="completed challenge" Feb 07 19:15:01 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:01] [connect] Successful connection Feb 07 19:15:01 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:01+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:01 volumio-stefan volumio[5101]: info: Loading plugin "i2s_dacs"... Feb 07 19:15:01 volumio-stefan volumio[5101]: info: Loading plugin "volumiodiscovery"... Feb 07 19:15:01 volumio-stefan volumio[5101]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:01 volumio-stefan volumio[5101]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:01 volumio-stefan volumio[5101]: *** WARNING *** For more information see Feb 07 19:15:01 volumio-stefan volumio[5101]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:01 volumio-stefan volumio[5101]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:01 volumio-stefan volumio[5101]: *** WARNING *** For more information see Feb 07 19:15:01 volumio-stefan node[5101]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:01 volumio-stefan node[5101]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:01 volumio-stefan node[5101]: *** WARNING *** For more information see Feb 07 19:15:01 volumio-stefan node[5101]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:01 volumio-stefan node[5101]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:01 volumio-stefan node[5101]: *** WARNING *** For more information see Feb 07 19:15:01 volumio-stefan volumio[5101]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 19:15:02 volumio-stefan volumio[5101]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 19:15:02 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:15:02 volumio-stefan volumio[5101]: info: Loading plugin "spop"... Feb 07 19:15:02 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:02+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:15:02 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:02+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:02 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:02+02:00" level=debug msg="completed challenge" Feb 07 19:15:02 volumio-stefan volumio[5101]: info: Loading plugin "now_playing"... Feb 07 19:15:03 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:03+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:03 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:03+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:03 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:03+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:33128->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:15:03 volumio-stefan go-librespot[5124]: time="2026-02-07T19:15:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:33128->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:15:03 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:03 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "outputs"... Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "albumart"... Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Plugin example_plugin is not enabled Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "inputs"... Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "updater_comm"... Feb 07 19:15:04 volumio-stefan sudo[5149]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Plugin mpdemulation is not enabled Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "rest_api"... Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "websocket"... Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Starting Socket.io Server version 1.7.4 Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "backup_restore"... Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Applying required configuration parameters for plugin backup_restore Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading plugin "Systeminfo"... Feb 07 19:15:04 volumio-stefan volumio[5172]: Forking 3 albumart workers Feb 07 19:15:04 volumio-stefan volumio[5101]: info: Loading i18n strings for locale en Feb 07 19:15:04 volumio-stefan volumio[5101]: Updating browse sources language Feb 07 19:15:04 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::initPlayerControls Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: Express server listening on port 3000 Feb 07 19:15:05 volumio-stefan volumio[5101]: [Metrics] WebUI: 7s 289.00ms Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::resetVolumioState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::getcurrentVolume Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::pushState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Volumio Network Manager: Network status updated: 2 Feb 07 19:15:05 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770484501 101 Feb 07 19:15:05 volumio-stefan volumio[5101]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Reloading queue from file Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::setRepeat null single undefined Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::pushState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::setRandom null Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreStateMachine::pushState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Setting Device type: Raspberry PI Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Completed loading Core Plugins Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Preparing to generate the ALSA configuration file Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Asound.conf file unchanged, so no further update is needed Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Output device has changed, restarting MPD Feb 07 19:15:05 volumio-stefan volumio[5101]: info: ___________ START PLUGINS ___________ Feb 07 19:15:05 volumio-stefan volumio[5101]: info: ControllerMpd::onStart: Initializing MPD Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Creating MPD Configuration file Feb 07 19:15:05 volumio-stefan sudo[5222]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:15:05 volumio-stefan sudo[5222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:15:05 volumio-stefan volumio[5101]: info: [1770484505641] CoreMusicLibrary::Adding element Last_100 Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:05 volumio-stefan sudo[5224]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:15:05 volumio-stefan sudo[5222]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:05 volumio-stefan sudo[5224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:15:05 volumio-stefan sudo[5226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:15:05 volumio-stefan volumio[5101]: info: [1770484505660] CoreMusicLibrary::Adding element Webradio Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:05 volumio-stefan sudo[5226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:05 volumio-stefan sudo[5226]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:05 volumio-stefan sudo[5228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:15:05 volumio-stefan sudo[5228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Initializing BBC Radios Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:05 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:05 volumio-stefan volumio[5101]: info: Creating Spotify config file Feb 07 19:15:05 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:05 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 19:15:05 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 19:15:05 volumio-stefan systemd[1]: mpd.service: Consumed 3.309s CPU time. Feb 07 19:15:05 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 19:15:05 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 19:15:05 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 19:15:05 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 19:15:05 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 19:15:06 volumio-stefan sudo[5247]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 19:15:06 volumio-stefan sudo[5247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 19:15:06 volumio-stefan sudo[5247]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:06 volumio-stefan volumio[5184]: Starting albumart workers Feb 07 19:15:06 volumio-stefan volumio[5182]: Starting albumart workers Feb 07 19:15:06 volumio-stefan volumio[5183]: Starting albumart workers Feb 07 19:15:06 volumio-stefan volumio[5101]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 19:15:06 volumio-stefan volumio[5101]: info: Volumio Calling Home Feb 07 19:15:06 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 19:15:06 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:07 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:07 volumio-stefan go-librespot[5265]: go-librespot daemon starting... Feb 07 19:15:07 volumio-stefan volumio[5101]: info: [now-playing] App is listening on port 4004. Feb 07 19:15:07 volumio-stefan go-librespot[5266]: time="2026-02-07T19:15:07+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:07 volumio-stefan volumio[5101]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 19:15:07 volumio-stefan volumio[5101]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:15:07 volumio-stefan volumio[5101]: info: Discovery: Found device Volumio Stefan Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:07 volumio-stefan volumio[5101]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:15:07 volumio-stefan volumio[5101]: info: Discovery: Found device Volumio Stefan Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:07 volumio-stefan volumio[5101]: info: MPD Permissions set Feb 07 19:15:07 volumio-stefan volumio[5101]: info: MPD Permissions set Feb 07 19:15:07 volumio-stefan volumio[5101]: info: Spotify config file written Feb 07 19:15:07 volumio-stefan sudo[5274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 19:15:07 volumio-stefan sudo[5274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:07 volumio-stefan volumio[5101]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 19:15:07 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 19:15:07 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 19:15:07 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:07 volumio-stefan volumio[5101]: info: Volumio called home Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:07 volumio-stefan go-librespot[5277]: go-librespot daemon starting... Feb 07 19:15:07 volumio-stefan sudo[5274]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02:00" level=debug msg="app state loaded" Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:07 volumio-stefan volumio[5101]: info: No need to fix Spotify hosts Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:07 volumio-stefan volumio[5101]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02: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]" Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:07 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02: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]" Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02: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]" Feb 07 19:15:07 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:07+02:00" level=info msg="zeroconf server listening on port 45431" Feb 07 19:15:08 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:08+02:00" level=debug msg="obtained new client token: AACm0pU35302o16Fvpseq0UD3JQwHjBs1gg1ZOfR/PxX4xt8aW2o6DgRoN3//ch8f0txCGZjwGhT/YH8jioBCJNaagNdVWGL3m120Au0Dt4x59xDj/fRkQNSKH/oWoPMWl5xhhCnfh3pcjJIUn9q62ciQtNEFMdM6JJRXezleQWctqc90ye3O/JMDZdYed2aIylFzr/Ekk5RRIqwNrEV53ZX1qDsBwJfKPTDHjNE1ELYTsboXUnj" Feb 07 19:15:08 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:08+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:08 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:08 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:08+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:08 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:41294->104.199.65.9:443: read: connection reset by peer" Feb 07 19:15:09 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:09 volumio-stefan mpd[5249]: 2026-02-07T19:15:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 19:15:09 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 19:15:09 volumio-stefan sudo[5228]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:09 volumio-stefan sudo[5224]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:09 volumio-stefan volumio[5101]: info: Completed starting Core Plugins Feb 07 19:15:09 volumio-stefan volumio[5101]: info: ------------------------------------------- Feb 07 19:15:09 volumio-stefan volumio[5101]: info: ----- MyVolumio plugins startup ---- Feb 07 19:15:09 volumio-stefan volumio[5101]: info: ------------------------------------------- Feb 07 19:15:09 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 19:15:09 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:09+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:51610->104.199.65.9:80: read: connection reset by peer" Feb 07 19:15:09 volumio-stefan volumio[5101]: error: MPD error: The expression evaluated to a falsy value: Feb 07 19:15:09 volumio-stefan volumio[5101]: assert.ok(self.idling) Feb 07 19:15:09 volumio-stefan volumio[5101]: error: The expression evaluated to a falsy value: Feb 07 19:15:09 volumio-stefan volumio[5101]: assert.ok(self.idling) Feb 07 19:15:09 volumio-stefan volumio[5101]: info: MPD running with PID5249 Feb 07 19:15:09 volumio-stefan volumio[5101]: ,establishing connection Feb 07 19:15:09 volumio-stefan volumio[5101]: error: updateQueue error: null Feb 07 19:15:09 volumio-stefan volumio[5101]: error: updateQueue error: null Feb 07 19:15:10 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:10+02:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 07 19:15:10 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 19:15:10 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:10+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:10 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:10+02:00" level=debug msg="completed challenge" Feb 07 19:15:10 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:10+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:10 volumio-stefan volumio[5101]: info: go-librespot daemon successfully initialized Feb 07 19:15:11 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:11+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:15:11 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:11+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:11 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:11+02:00" level=debug msg="completed challenge" Feb 07 19:15:11 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:11+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:11 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28825. Feb 07 19:15:11 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:12 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:12 volumio-stefan upmpdcli[5323]: Could not open config: /tmp/upmpdcli.conf Feb 07 19:15:12 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:12 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 19:15:12 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:12+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:12 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:12+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:12 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:12+02:00" level=debug msg="completed challenge" Feb 07 19:15:12 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:12+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:12 volumio-stefan go-librespot[5291]: time="2026-02-07T19:15:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:12 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:12 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:13 volumio-stefan volumio[5101]: info: Initializing connection to go-librespot Websocket Feb 07 19:15:13 volumio-stefan volumio[5101]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 19:15:14 volumio-stefan volumio[5101]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 19:15:15 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 19:15:15 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:15 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:15 volumio-stefan go-librespot[5325]: go-librespot daemon starting... Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02:00" level=debug msg="app state loaded" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02: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]" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02: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]" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02: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]" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02:00" level=info msg="zeroconf server listening on port 38965" Feb 07 19:15:15 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:15+02:00" level=debug msg="obtained new client token: AACbrh7lgSaIkA77WE21PnPuIXABtgmtM++B+QEzWlB9gLcNVpOC/Osv+TTg2vo0qsrFcwX2dZwBHxlrre1cDvyzu54sr/sd1smHEMr3Sq78IrW2oVzf1A6AjsgMtijTyaTZssDUtgVegj9hCbuHkOuFe5xDMiUoAGx5l1UmvJjgqpr+JxtOdeDurk0U7MNThzNcLTrm/XD4g0pHsrrzvTDa54PLy7c/Jt1/W264ErlBqj8YnW6AWJY=" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="completed challenge" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="completed challenge" Feb 07 19:15:16 volumio-stefan volumio[5101]: info: Initializing connection to go-librespot Websocket Feb 07 19:15:16 volumio-stefan volumio[5101]: info: Connection to go-librespot Websocket established Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=debug msg="new websocket client" Feb 07 19:15:16 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:17 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:17 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:17+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:17 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:17+02:00" level=debug msg="completed challenge" Feb 07 19:15:17 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 19:15:17 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 19:15:18 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:18+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 19:15:18 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:18+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:18 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:18+02:00" level=debug msg="completed challenge" Feb 07 19:15:18 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:18+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:18 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 19:15:18 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 19:15:18 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:18 volumio-stefan volumio[5101]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:18 volumio-stefan volumio[5101]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 19:15:18 volumio-stefan volumio[5101]: info: MyVolumio login type: Token Feb 07 19:15:18 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 19:15:18 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 19:15:19 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:19+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 19:15:19 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:19+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:19 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:19+02:00" level=debug msg="completed challenge" Feb 07 19:15:19 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 19:15:19 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 19:15:19 volumio-stefan volumio[5101]: info: Streaming services startup Feb 07 19:15:19 volumio-stefan volumio[5101]: info: Starting Streaming Daemon Feb 07 19:15:19 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:19+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:19 volumio-stefan sudo[5336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 19:15:19 volumio-stefan sudo[5336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:19 volumio-stefan volumio[5101]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 19:15:19 volumio-stefan sudo[5336]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:19 volumio-stefan volumio[5101]: error: Cannot start Volumio Streaming Daemon Feb 07 19:15:19 volumio-stefan volumio[5101]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 19:15:19 volumio-stefan volumio[5101]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 19:15:19 volumio-stefan volumio[5101]: info: Getting Spotify volume Feb 07 19:15:19 volumio-stefan volumio[5101]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 07 19:15:20 volumio-stefan volumio[5101]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:20 volumio-stefan volumio[5101]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:20 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 19:15:20 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:20+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:20 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:20+02:00" level=debug msg="completed challenge" Feb 07 19:15:20 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:20+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:20 volumio-stefan go-librespot[5326]: time="2026-02-07T19:15:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:20 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:20 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:20 volumio-stefan volumio[5101]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:15:20 volumio-stefan volumio[5101]: Error: socket hang up Feb 07 19:15:20 volumio-stefan volumio[5101]: at connResetException (node:internal/errors:720:14) Feb 07 19:15:20 volumio-stefan volumio[5101]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 19:15:20 volumio-stefan volumio[5101]: at Socket.emit (node:events:526:35) Feb 07 19:15:20 volumio-stefan volumio[5101]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 19:15:20 volumio-stefan volumio[5101]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 19:15:20 volumio-stefan volumio[5101]: code: 'ECONNRESET', Feb 07 19:15:20 volumio-stefan volumio[5101]: response: undefined Feb 07 19:15:20 volumio-stefan volumio[5101]: } Feb 07 19:15:20 volumio-stefan volumio[5101]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:15:20 volumio-stefan sudo[5370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 19:14' Feb 07 19:15:20 volumio-stefan sudo[5370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:21 volumio-stefan sudo[5370]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:21 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 19:15:21 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 19:15:21 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:21 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 19:15:21 volumio-stefan systemd[1]: volumio.service: Consumed 24.875s CPU time. Feb 07 19:15:21 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 19:15:21 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 19:15:21 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9451. Feb 07 19:15:21 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 19:15:21 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 19:15:21 volumio-stefan systemd[1]: volumio.service: Consumed 24.875s CPU time. Feb 07 19:15:21 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 19:15:21 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 19:15:23 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 19:15:23 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:23 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:23 volumio-stefan volumio[5384]: info: ----- Volumio3 ---- Feb 07 19:15:23 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:23 volumio-stefan volumio[5384]: info: ----- System startup ---- Feb 07 19:15:23 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:23 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:23 volumio-stefan go-librespot[5405]: go-librespot daemon starting... Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=debug msg="app state loaded" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02: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]" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02: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]" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02: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]" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=info msg="zeroconf server listening on port 45867" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=debug msg="obtained new client token: AACJbQ+3zz8nFOoixxo1Duk6nv1IllG53oAFB4Ff2S7+VbdOY8gx6pDDJWwVqJRG2juOMCOlZTwYe5c1qE+NUWGe5doZsa6w0Q58aukPGgoor/7BIDWl9dkdZA0gcFlPEEUQUF7gTiqd1bI/QgD/JDJpkz0/LlYyx6wMUxR0orkmQh5Uz5EBole6v0YraguyYQWaMq3H6Y5disBLmkfJ1RZTGPy10oJI4hINdRFGGrztG3cXOL5BH0w=" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=debug msg="completed challenge" Feb 07 19:15:23 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:24 volumio-stefan volumio[5384]: info: MYVOLUMIO Environment detected Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Plugin folders cleanup Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning into folder /volumio/app/plugins/ Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category audio_interface Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category miscellanea Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category music_service Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category plugins.json Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category system_controller Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category user_interface Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning into folder /data/plugins/ Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category music_service Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category system_controller Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Scanning category user_interface Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Plugin folders cleanup completed Feb 07 19:15:24 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:24 volumio-stefan volumio[5384]: info: ----- Core plugins startup ---- Feb 07 19:15:24 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Adding plugin upnp to MyMusic Plugins Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Loading plugins from folder /data/plugins/ Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Loading plugin "system"... Feb 07 19:15:24 volumio-stefan volumio[5384]: info: Loading plugin "appearance"... Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=debug msg="completed challenge" Feb 07 19:15:24 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:24+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "network"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Refreshing Cached IP Addresses Feb 07 19:15:25 volumio-stefan sudo[5422]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 19:15:25 volumio-stefan sudo[5422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:25 volumio-stefan sudo[5424]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 19:15:25 volumio-stefan sudo[5424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:25 volumio-stefan sudo[5422]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:25 volumio-stefan sudo[5424]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "services"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "alsa_controller"... Feb 07 19:15:25 volumio-stefan sudo[5432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 19:15:25 volumio-stefan sudo[5432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:25 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "wizard"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "networkfs"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Starting Udev Watcher for removable devices Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Ignoring mount for partition: boot Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Ignoring mount for partition: volumio Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Ignoring mount for partition: volumio_data Feb 07 19:15:25 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "volumio_command_line_client"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Plugin upnp is not enabled Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "my_music"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "mpd"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Plugin upnp_browser is not enabled Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "alarm-clock"... Feb 07 19:15:25 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:25+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Plugin airplay_emulation is not enabled Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "last_100"... Feb 07 19:15:25 volumio-stefan volumio[5384]: info: Loading plugin "webradio"... Feb 07 19:15:26 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:26+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:26 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:26+02:00" level=debug msg="completed challenge" Feb 07 19:15:26 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:26] [connect] Successful connection Feb 07 19:15:26 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:26+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:26 volumio-stefan volumio[5384]: info: Loading plugin "i2s_dacs"... Feb 07 19:15:26 volumio-stefan volumio[5384]: info: Loading plugin "volumiodiscovery"... Feb 07 19:15:27 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:27+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:27 volumio-stefan volumio[5384]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:27 volumio-stefan volumio[5384]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:27 volumio-stefan volumio[5384]: *** WARNING *** For more information see Feb 07 19:15:27 volumio-stefan volumio[5384]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:27 volumio-stefan volumio[5384]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:27 volumio-stefan volumio[5384]: *** WARNING *** For more information see Feb 07 19:15:27 volumio-stefan node[5384]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:27 volumio-stefan node[5384]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:27 volumio-stefan node[5384]: *** WARNING *** For more information see Feb 07 19:15:27 volumio-stefan node[5384]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:27 volumio-stefan node[5384]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:27 volumio-stefan node[5384]: *** WARNING *** For more information see Feb 07 19:15:27 volumio-stefan volumio[5384]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 19:15:27 volumio-stefan volumio[5384]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 19:15:27 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:15:27 volumio-stefan volumio[5384]: info: Loading plugin "spop"... Feb 07 19:15:27 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:27+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:27 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:27+02:00" level=debug msg="completed challenge" Feb 07 19:15:27 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28826. Feb 07 19:15:27 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:27 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:27 volumio-stefan upmpdcli[5454]: Could not open config: /tmp/upmpdcli.conf Feb 07 19:15:27 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:27 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 19:15:27 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:27+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:28 volumio-stefan volumio[5384]: info: Loading plugin "now_playing"... Feb 07 19:15:28 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:28+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:28 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:28+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:39732->104.199.65.9:443: read: connection reset by peer" Feb 07 19:15:28 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:28+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "outputs"... Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "albumart"... Feb 07 19:15:29 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:29+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:29 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:29+02:00" level=debug msg="completed challenge" Feb 07 19:15:29 volumio-stefan sudo[5432]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Plugin example_plugin is not enabled Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "inputs"... Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "updater_comm"... Feb 07 19:15:29 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:29+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:29 volumio-stefan go-librespot[5406]: time="2026-02-07T19:15:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:29 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:29 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Plugin mpdemulation is not enabled Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "rest_api"... Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "websocket"... Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Starting Socket.io Server version 1.7.4 Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "backup_restore"... Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Applying required configuration parameters for plugin backup_restore Feb 07 19:15:29 volumio-stefan volumio[5384]: info: Loading plugin "Systeminfo"... Feb 07 19:15:29 volumio-stefan volumio[5455]: Forking 3 albumart workers Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Loading i18n strings for locale en Feb 07 19:15:30 volumio-stefan volumio[5384]: Updating browse sources language Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::initPlayerControls Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: Express server listening on port 3000 Feb 07 19:15:30 volumio-stefan volumio[5384]: [Metrics] WebUI: 7s 402.94ms Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::resetVolumioState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::getcurrentVolume Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::pushState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Volumio Network Manager: Network status updated: 2 Feb 07 19:15:30 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770484526 101 Feb 07 19:15:30 volumio-stefan volumio[5384]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Reloading queue from file Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::setRepeat null single undefined Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::pushState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::setRandom null Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreStateMachine::pushState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Setting Device type: Raspberry PI Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Completed loading Core Plugins Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Preparing to generate the ALSA configuration file Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Asound.conf file unchanged, so no further update is needed Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Output device has changed, restarting MPD Feb 07 19:15:30 volumio-stefan volumio[5384]: info: ___________ START PLUGINS ___________ Feb 07 19:15:30 volumio-stefan sudo[5508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:15:30 volumio-stefan sudo[5508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:30 volumio-stefan volumio[5384]: info: ControllerMpd::onStart: Initializing MPD Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Creating MPD Configuration file Feb 07 19:15:30 volumio-stefan sudo[5508]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:15:30 volumio-stefan sudo[5510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:15:30 volumio-stefan volumio[5384]: info: [1770484530699] CoreMusicLibrary::Adding element Last_100 Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:30 volumio-stefan sudo[5510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:15:30 volumio-stefan volumio[5384]: info: [1770484530710] CoreMusicLibrary::Adding element Webradio Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Initializing BBC Radios Feb 07 19:15:30 volumio-stefan sudo[5516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:15:30 volumio-stefan sudo[5516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:30 volumio-stefan sudo[5513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:15:30 volumio-stefan sudo[5513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:30 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 19:15:30 volumio-stefan sudo[5513]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:30 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 19:15:30 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 19:15:30 volumio-stefan systemd[1]: mpd.service: Consumed 3.311s CPU time. Feb 07 19:15:30 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 19:15:30 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 19:15:30 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:30 volumio-stefan volumio[5384]: info: Creating Spotify config file Feb 07 19:15:30 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:30 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 19:15:30 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 19:15:31 volumio-stefan sudo[5533]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 19:15:31 volumio-stefan sudo[5533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 19:15:31 volumio-stefan sudo[5533]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:31 volumio-stefan volumio[5468]: Starting albumart workers Feb 07 19:15:31 volumio-stefan volumio[5467]: Starting albumart workers Feb 07 19:15:31 volumio-stefan volumio[5466]: Starting albumart workers Feb 07 19:15:31 volumio-stefan volumio[5384]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 19:15:31 volumio-stefan volumio[5384]: info: Volumio Calling Home Feb 07 19:15:32 volumio-stefan volumio[5384]: info: [now-playing] App is listening on port 4004. Feb 07 19:15:32 volumio-stefan volumio[5384]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 19:15:32 volumio-stefan volumio[5384]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:15:32 volumio-stefan volumio[5384]: info: Discovery: Found device Volumio Stefan Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:32 volumio-stefan volumio[5384]: info: MPD Permissions set Feb 07 19:15:32 volumio-stefan volumio[5384]: info: MPD Permissions set Feb 07 19:15:32 volumio-stefan volumio[5384]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:15:32 volumio-stefan volumio[5384]: info: Discovery: Found device Volumio Stefan Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:32 volumio-stefan volumio[5384]: info: Spotify config file written Feb 07 19:15:32 volumio-stefan sudo[5557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 19:15:32 volumio-stefan sudo[5557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:32 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 19:15:32 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:32 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:32 volumio-stefan go-librespot[5560]: go-librespot daemon starting... Feb 07 19:15:32 volumio-stefan go-librespot[5561]: time="2026-02-07T19:15:32+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:32 volumio-stefan go-librespot[5561]: time="2026-02-07T19:15:32+02:00" level=debug msg="app state loaded" Feb 07 19:15:32 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 19:15:32 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 19:15:32 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:32 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:32 volumio-stefan volumio[5384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 19:15:32 volumio-stefan sudo[5557]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:32 volumio-stefan volumio[5384]: info: Volumio called home Feb 07 19:15:32 volumio-stefan go-librespot[5569]: go-librespot daemon starting... Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:32+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:32 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:32+02:00" level=debug msg="app state loaded" Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:32 volumio-stefan volumio[5384]: info: No need to fix Spotify hosts Feb 07 19:15:32 volumio-stefan volumio[5384]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:32 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02: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]" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02: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]" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02: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]" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02:00" level=info msg="zeroconf server listening on port 42381" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02:00" level=debug msg="obtained new client token: AAAo7P+GJjF7VDu7tpFnTKGbKzQltQLx4UPXgMnfSUUt1RVLqjOE2HGgXVOshIbgEYoytTCzwLUD9yX1hDo4DYGD8euViKK9FOeplgHT3Jw9H8LbFQms1E7hEFLEHULKEFr/ICahT/xvY6hff9Tdqm4TTp+0tAlg2lQLNTUs+CMlFvtxFvdM5Qk4+ZjFeFkb1+nNgCVyspZ9uz2lqiha3pzyigX5/ql7/HQDL0jhDXb+62eAd0ME" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:56870->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:33 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:33+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:53070->104.199.65.9:443: read: connection reset by peer" Feb 07 19:15:34 volumio-stefan mpd[5535]: 2026-02-07T19:15:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 19:15:34 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 19:15:34 volumio-stefan sudo[5510]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:34 volumio-stefan sudo[5516]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:34 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:34+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:34 volumio-stefan volumio[5384]: info: Completed starting Core Plugins Feb 07 19:15:34 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:34 volumio-stefan volumio[5384]: info: ----- MyVolumio plugins startup ---- Feb 07 19:15:34 volumio-stefan volumio[5384]: info: ------------------------------------------- Feb 07 19:15:34 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 19:15:34 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:34+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:40424->104.199.65.9:80: read: connection reset by peer" Feb 07 19:15:34 volumio-stefan volumio[5384]: error: MPD error: The expression evaluated to a falsy value: Feb 07 19:15:34 volumio-stefan volumio[5384]: assert.ok(self.idling) Feb 07 19:15:34 volumio-stefan volumio[5384]: error: The expression evaluated to a falsy value: Feb 07 19:15:34 volumio-stefan volumio[5384]: assert.ok(self.idling) Feb 07 19:15:34 volumio-stefan volumio[5384]: error: updateQueue error: null Feb 07 19:15:34 volumio-stefan volumio[5384]: info: MPD running with PID5535 Feb 07 19:15:34 volumio-stefan volumio[5384]: ,establishing connection Feb 07 19:15:34 volumio-stefan volumio[5384]: error: updateQueue error: null Feb 07 19:15:35 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:35+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 19:15:35 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:35+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 19:15:35 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:35+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:35 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:35+02:00" level=debug msg="completed challenge" Feb 07 19:15:35 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:35+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:35 volumio-stefan volumio[5384]: info: go-librespot daemon successfully initialized Feb 07 19:15:36 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:36+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:15:36 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:36+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:36 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:36+02:00" level=debug msg="completed challenge" Feb 07 19:15:36 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:36+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:37 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:37 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:37+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:37 volumio-stefan go-librespot[5570]: time="2026-02-07T19:15:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:37 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:37 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:38 volumio-stefan volumio[5384]: info: Initializing connection to go-librespot Websocket Feb 07 19:15:38 volumio-stefan volumio[5384]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 19:15:39 volumio-stefan volumio[5384]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 19:15:40 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 19:15:40 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:40 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:40 volumio-stefan go-librespot[5608]: go-librespot daemon starting... Feb 07 19:15:40 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:40+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:40 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:40+02:00" level=debug msg="app state loaded" Feb 07 19:15:40 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02: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]" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02: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]" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02: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]" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=info msg="zeroconf server listening on port 38101" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=debug msg="obtained new client token: AABNk4F9ETLlMJk027xtR+gh3CKWcjQNDfNWWbfTIpv2r9XNObaudkIqbeNOQaAPbTsPI8B0wN+KsyQx6DS25ObvPeRIgACjvVRhrcnz21d5HYT+xoRoQMs3IhVMCtVJchvErF3qyOsJui5q/fxA6krcaK+MFnH9ahdFzQUAWBC7TrrNrLI7f20vZ2ASwntQjd+DW/GeAklL3FEaYP+58GT/KzbMjs6BHYdH2d0NQRqEqz8quu9e" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:41 volumio-stefan volumio[5384]: info: Initializing connection to go-librespot Websocket Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=debug msg="new websocket client" Feb 07 19:15:41 volumio-stefan volumio[5384]: info: Connection to go-librespot Websocket established Feb 07 19:15:41 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:41+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:53082->104.199.65.9:443: read: connection reset by peer" Feb 07 19:15:42 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28827. Feb 07 19:15:42 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:42 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:42+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:42 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:42 volumio-stefan upmpdcli[5618]: Could not open config: /tmp/upmpdcli.conf Feb 07 19:15:42 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:42 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 19:15:42 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:42+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:42 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:42+02:00" level=debug msg="completed challenge" Feb 07 19:15:42 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:42+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:43 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:43+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 19:15:43 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 19:15:43 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:43+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:43 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:43+02:00" level=debug msg="completed challenge" Feb 07 19:15:43 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:43+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:44 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 19:15:44 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 19:15:44 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:44 volumio-stefan volumio[5384]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:44 volumio-stefan volumio[5384]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 19:15:44 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 19:15:44 volumio-stefan volumio[5384]: info: MyVolumio login type: Token Feb 07 19:15:44 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 19:15:44 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 19:15:44 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:44+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:44 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:44+02:00" level=debug msg="completed challenge" Feb 07 19:15:44 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:44+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:45 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:45+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:15:45 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 19:15:45 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 19:15:45 volumio-stefan volumio[5384]: info: Streaming services startup Feb 07 19:15:45 volumio-stefan volumio[5384]: info: Starting Streaming Daemon Feb 07 19:15:45 volumio-stefan sudo[5620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 19:15:45 volumio-stefan sudo[5620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:45 volumio-stefan volumio[5384]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 19:15:45 volumio-stefan sudo[5620]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:45 volumio-stefan volumio[5384]: info: Getting Spotify volume Feb 07 19:15:45 volumio-stefan volumio[5384]: error: Cannot start Volumio Streaming Daemon Feb 07 19:15:45 volumio-stefan volumio[5384]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 19:15:45 volumio-stefan volumio[5384]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 19:15:45 volumio-stefan volumio[5384]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 07 19:15:45 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:45+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:45 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:45+02:00" level=debug msg="completed challenge" Feb 07 19:15:45 volumio-stefan volumio[5384]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:45 volumio-stefan volumio[5384]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:45 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:45+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:45 volumio-stefan go-librespot[5609]: time="2026-02-07T19:15:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:45 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:45 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:45 volumio-stefan volumio[5384]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:15:45 volumio-stefan volumio[5384]: Error: socket hang up Feb 07 19:15:45 volumio-stefan volumio[5384]: at connResetException (node:internal/errors:720:14) Feb 07 19:15:45 volumio-stefan volumio[5384]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 19:15:45 volumio-stefan volumio[5384]: at Socket.emit (node:events:526:35) Feb 07 19:15:45 volumio-stefan volumio[5384]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 19:15:45 volumio-stefan volumio[5384]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 19:15:45 volumio-stefan volumio[5384]: code: 'ECONNRESET', Feb 07 19:15:45 volumio-stefan volumio[5384]: response: undefined Feb 07 19:15:45 volumio-stefan volumio[5384]: } Feb 07 19:15:45 volumio-stefan volumio[5384]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:15:46 volumio-stefan sudo[5654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 19:14' Feb 07 19:15:46 volumio-stefan sudo[5654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:46 volumio-stefan sudo[5654]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:46 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 19:15:46 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 19:15:46 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:46 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 19:15:46 volumio-stefan systemd[1]: volumio.service: Consumed 25.006s CPU time. Feb 07 19:15:46 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 19:15:46 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 19:15:46 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9452. Feb 07 19:15:47 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 19:15:47 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 19:15:47 volumio-stefan systemd[1]: volumio.service: Consumed 25.006s CPU time. Feb 07 19:15:47 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 19:15:47 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 19:15:48 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 19:15:48 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:48 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:48 volumio-stefan go-librespot[5687]: go-librespot daemon starting... Feb 07 19:15:48 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:15:48 volumio-stefan volumio[5666]: info: ----- Volumio3 ---- Feb 07 19:15:48 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:15:48 volumio-stefan volumio[5666]: info: ----- System startup ---- Feb 07 19:15:48 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:15:48 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:48+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:48 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:48+02:00" level=debug msg="app state loaded" Feb 07 19:15:48 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02: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]" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02: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]" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02: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]" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02:00" level=info msg="zeroconf server listening on port 43667" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02:00" level=debug msg="obtained new client token: AAC3hVGdsTEeO+5co0EtJ0qdYstyA/ftka8eiMToqa5jHYfjw273bNSlclT5qS5qhvdU21qn6SmLjl2UdlyieE7eTd+yKUEPTA5FB/9ZMpOsleYPeNBBn9w2f06dC0B01anQ+rShv8THgC7rt0hXnYND0PI3UpBJuI21466ED63u4F+NgaK3b3kAaZIZ+FxnYrizeUgVgQRvYU0hcL/ddjtKmV20sb43UABd4PMdXStu8OgnVNVSIqA=" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:49 volumio-stefan volumio[5666]: info: MYVOLUMIO Environment detected Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Plugin folders cleanup Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning into folder /volumio/app/plugins/ Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category audio_interface Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category miscellanea Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category music_service Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category plugins.json Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category system_controller Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category user_interface Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning into folder /data/plugins/ Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category music_service Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category system_controller Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Scanning category user_interface Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Plugin folders cleanup completed Feb 07 19:15:49 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:15:49 volumio-stefan volumio[5666]: info: ----- Core plugins startup ---- Feb 07 19:15:49 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Adding plugin upnp to MyMusic Plugins Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Loading plugins from folder /data/plugins/ Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Loading plugin "system"... Feb 07 19:15:49 volumio-stefan volumio[5666]: info: Loading plugin "appearance"... Feb 07 19:15:49 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:49+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:50 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:50+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "network"... Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Refreshing Cached IP Addresses Feb 07 19:15:50 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:50+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:15:50 volumio-stefan sudo[5704]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 19:15:50 volumio-stefan sudo[5704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:50 volumio-stefan sudo[5704]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:50 volumio-stefan sudo[5706]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 19:15:50 volumio-stefan sudo[5706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:50 volumio-stefan sudo[5706]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "services"... Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "alsa_controller"... Feb 07 19:15:50 volumio-stefan sudo[5715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 19:15:50 volumio-stefan sudo[5715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:50 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:50+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:50 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:50+02:00" level=debug msg="completed challenge" Feb 07 19:15:50 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "wizard"... Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "networkfs"... Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Starting Udev Watcher for removable devices Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Ignoring mount for partition: boot Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Ignoring mount for partition: volumio Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Ignoring mount for partition: volumio_data Feb 07 19:15:50 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "volumio_command_line_client"... Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Plugin upnp is not enabled Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "my_music"... Feb 07 19:15:50 volumio-stefan volumio[5666]: info: Loading plugin "mpd"... Feb 07 19:15:50 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:50+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:51 volumio-stefan volumio[5666]: info: Plugin upnp_browser is not enabled Feb 07 19:15:51 volumio-stefan volumio[5666]: info: Loading plugin "alarm-clock"... Feb 07 19:15:51 volumio-stefan volumio[5666]: info: Plugin airplay_emulation is not enabled Feb 07 19:15:51 volumio-stefan volumio[5666]: info: Loading plugin "last_100"... Feb 07 19:15:51 volumio-stefan volumio[5666]: info: Loading plugin "webradio"... Feb 07 19:15:51 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:51+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 19:15:51 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:51] [connect] Successful connection Feb 07 19:15:51 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:51+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:51 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:51+02:00" level=debug msg="completed challenge" Feb 07 19:15:51 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:51+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:52 volumio-stefan volumio[5666]: info: Loading plugin "i2s_dacs"... Feb 07 19:15:52 volumio-stefan volumio[5666]: info: Loading plugin "volumiodiscovery"... Feb 07 19:15:52 volumio-stefan volumio[5666]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:52 volumio-stefan volumio[5666]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:52 volumio-stefan volumio[5666]: *** WARNING *** For more information see Feb 07 19:15:52 volumio-stefan volumio[5666]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:52 volumio-stefan volumio[5666]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:52 volumio-stefan volumio[5666]: *** WARNING *** For more information see Feb 07 19:15:52 volumio-stefan node[5666]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:52 volumio-stefan node[5666]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:52 volumio-stefan node[5666]: *** WARNING *** For more information see Feb 07 19:15:52 volumio-stefan node[5666]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:15:52 volumio-stefan node[5666]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:15:52 volumio-stefan node[5666]: *** WARNING *** For more information see Feb 07 19:15:52 volumio-stefan volumio[5666]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 19:15:52 volumio-stefan volumio[5666]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 19:15:52 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:15:52 volumio-stefan volumio[5666]: info: Loading plugin "spop"... Feb 07 19:15:52 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 19:15:52 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:52+02:00" level=debug msg="completed keyexchange" Feb 07 19:15:52 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:52+02:00" level=debug msg="completed challenge" Feb 07 19:15:53 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:53+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:15:53 volumio-stefan volumio[5666]: info: Loading plugin "now_playing"... Feb 07 19:15:53 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:53+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:15:54 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:54+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:36118->104.199.241.202:80: read: connection reset by peer" Feb 07 19:15:54 volumio-stefan go-librespot[5688]: time="2026-02-07T19:15:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:36118->104.199.241.202:80: read: connection reset by peer" Feb 07 19:15:54 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:54 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "outputs"... Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "albumart"... Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Plugin example_plugin is not enabled Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "inputs"... Feb 07 19:15:54 volumio-stefan sudo[5715]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "updater_comm"... Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Plugin mpdemulation is not enabled Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "rest_api"... Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "websocket"... Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Starting Socket.io Server version 1.7.4 Feb 07 19:15:54 volumio-stefan volumio[5666]: info: Loading plugin "backup_restore"... Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Applying required configuration parameters for plugin backup_restore Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Loading plugin "Systeminfo"... Feb 07 19:15:55 volumio-stefan volumio[5737]: Forking 3 albumart workers Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Loading i18n strings for locale en Feb 07 19:15:55 volumio-stefan volumio[5666]: Updating browse sources language Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::initPlayerControls Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: Express server listening on port 3000 Feb 07 19:15:55 volumio-stefan volumio[5666]: [Metrics] WebUI: 7s 348.89ms Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::resetVolumioState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::getcurrentVolume Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::pushState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Volumio Network Manager: Network status updated: 2 Feb 07 19:15:55 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:15:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770484551 101 Feb 07 19:15:55 volumio-stefan volumio[5666]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Reloading queue from file Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::setRepeat null single undefined Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::pushState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::setRandom null Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreStateMachine::pushState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:55 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioPushState Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Setting Device type: Raspberry PI Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Completed loading Core Plugins Feb 07 19:15:55 volumio-stefan volumio[5666]: info: Preparing to generate the ALSA configuration file Feb 07 19:15:56 volumio-stefan volumio[5666]: info: Asound.conf file unchanged, so no further update is needed Feb 07 19:15:56 volumio-stefan volumio[5666]: info: Output device has changed, restarting MPD Feb 07 19:15:56 volumio-stefan sudo[5788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:15:56 volumio-stefan sudo[5788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:56 volumio-stefan volumio[5666]: info: ___________ START PLUGINS ___________ Feb 07 19:15:56 volumio-stefan sudo[5788]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:56 volumio-stefan volumio[5666]: info: ControllerMpd::onStart: Initializing MPD Feb 07 19:15:56 volumio-stefan volumio[5666]: info: Creating MPD Configuration file Feb 07 19:15:56 volumio-stefan sudo[5790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:15:56 volumio-stefan sudo[5790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:15:56 volumio-stefan volumio[5666]: info: [1770484556204] CoreMusicLibrary::Adding element Last_100 Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:15:56 volumio-stefan volumio[5666]: info: [1770484556220] CoreMusicLibrary::Adding element Webradio Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:15:56 volumio-stefan sudo[5794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:15:56 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:56 volumio-stefan volumio[5666]: info: Initializing BBC Radios Feb 07 19:15:56 volumio-stefan sudo[5794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:56 volumio-stefan sudo[5796]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:15:56 volumio-stefan sudo[5794]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:56 volumio-stefan sudo[5796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:56 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 19:15:56 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 19:15:56 volumio-stefan systemd[1]: mpd.service: Consumed 3.365s CPU time. Feb 07 19:15:56 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 19:15:56 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 19:15:56 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:56 volumio-stefan volumio[5666]: info: Creating Spotify config file Feb 07 19:15:56 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:56 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 19:15:56 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 19:15:56 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 19:15:56 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 19:15:56 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 19:15:56 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 19:15:56 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 19:15:56 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 19:15:56 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 19:15:56 volumio-stefan volumio[5747]: Starting albumart workers Feb 07 19:15:56 volumio-stefan volumio[5748]: Starting albumart workers Feb 07 19:15:56 volumio-stefan sudo[5815]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 19:15:56 volumio-stefan sudo[5815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 19:15:56 volumio-stefan sudo[5815]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:57 volumio-stefan volumio[5749]: Starting albumart workers Feb 07 19:15:57 volumio-stefan volumio[5666]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Volumio Calling Home Feb 07 19:15:57 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 19:15:57 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:57 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:57 volumio-stefan go-librespot[5821]: go-librespot daemon starting... Feb 07 19:15:57 volumio-stefan volumio[5666]: info: [now-playing] App is listening on port 4004. Feb 07 19:15:57 volumio-stefan go-librespot[5828]: time="2026-02-07T19:15:57+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:57 volumio-stefan volumio[5666]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Discovery: Found device Volumio Stefan Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:57 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28828. Feb 07 19:15:57 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Discovery: Found device Volumio Stefan Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:57 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:15:57 volumio-stefan volumio[5666]: info: MPD Permissions set Feb 07 19:15:57 volumio-stefan volumio[5666]: info: MPD Permissions set Feb 07 19:15:57 volumio-stefan upmpdcli[5840]: Could not open config: /tmp/upmpdcli.conf Feb 07 19:15:57 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:15:57 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Spotify config file written Feb 07 19:15:57 volumio-stefan sudo[5843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 19:15:57 volumio-stefan sudo[5843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:15:57 volumio-stefan volumio[5666]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 19:15:57 volumio-stefan volumio[5666]: info: Volumio called home Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:57 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 19:15:58 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:15:58 volumio-stefan volumio[5666]: info: No need to fix Spotify hosts Feb 07 19:15:58 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:15:58 volumio-stefan sudo[5843]: pam_unix(sudo:session): session closed for user root Feb 07 19:15:58 volumio-stefan go-librespot[5861]: go-librespot daemon starting... Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=debug msg="app state loaded" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:15:58 volumio-stefan volumio[5666]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioGetState Feb 07 19:15:58 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02: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]" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02: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]" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02: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]" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=info msg="zeroconf server listening on port 40289" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=debug msg="obtained new client token: AAALl3yllDor5KTnDqBvr04Ohe+/azemJmHPVmyLxozzTNEt/eWaTX/CtlF9ApkyKRAoZAcaHqOlhGCECcTVNehhnWUSUAax9ygPCvibU3ZLdR7uwXIUCKh2gHpGoDMjlQfMnoprMbDAyI98rw2EqUdD76ulOugfv4zKKG3DR3eq8o5ao3Io8BONAJY2ODB6ryIgNi+IcAbdblc+ETsXz7o1ZNrq1nybVLChSqqJ+hehE4hL0TCGbOI=" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:15:58 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:58+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:15:59 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:59+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:15:59 volumio-stefan go-librespot[5862]: time="2026-02-07T19:15:59+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:16:00 volumio-stefan mpd[5817]: 2026-02-07T19:16:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 19:16:00 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 19:16:00 volumio-stefan sudo[5790]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:00 volumio-stefan sudo[5796]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=debug msg="completed challenge" Feb 07 19:16:00 volumio-stefan volumio[5666]: info: Completed starting Core Plugins Feb 07 19:16:00 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:16:00 volumio-stefan volumio[5666]: info: ----- MyVolumio plugins startup ---- Feb 07 19:16:00 volumio-stefan volumio[5666]: info: ------------------------------------------- Feb 07 19:16:00 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:00 volumio-stefan volumio[5666]: error: MPD error: The expression evaluated to a falsy value: Feb 07 19:16:00 volumio-stefan volumio[5666]: assert.ok(self.idling) Feb 07 19:16:00 volumio-stefan volumio[5666]: error: The expression evaluated to a falsy value: Feb 07 19:16:00 volumio-stefan volumio[5666]: assert.ok(self.idling) Feb 07 19:16:00 volumio-stefan volumio[5666]: error: updateQueue error: null Feb 07 19:16:00 volumio-stefan volumio[5666]: info: MPD running with PID5817 Feb 07 19:16:00 volumio-stefan volumio[5666]: ,establishing connection Feb 07 19:16:00 volumio-stefan volumio[5666]: error: updateQueue error: null Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:00 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:00+02:00" level=debug msg="completed challenge" Feb 07 19:16:01 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:01+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:01 volumio-stefan volumio[5666]: info: go-librespot daemon successfully initialized Feb 07 19:16:01 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:01+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 07 19:16:01 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:01+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:16:02 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:02+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:02 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:02+02:00" level=debug msg="completed challenge" Feb 07 19:16:02 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:02+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:03 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:03+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:16:03 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:03+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:38918->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:16:03 volumio-stefan go-librespot[5862]: time="2026-02-07T19:16:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:38918->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:16:03 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:03 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:16:04 volumio-stefan volumio[5666]: info: Initializing connection to go-librespot Websocket Feb 07 19:16:04 volumio-stefan volumio[5666]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 19:16:05 volumio-stefan volumio[5666]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 19:16:06 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 19:16:06 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:06 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:06 volumio-stefan go-librespot[5890]: go-librespot daemon starting... Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=debug msg="app state loaded" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02: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]" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02: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]" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02: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]" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=info msg="zeroconf server listening on port 36105" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=debug msg="obtained new client token: AAALdaWFbQW9+ABSnSSyB8iLpLp7ku6IYT/xtCPDiiOir5jFRAucu0j9Ul0DrC3B+je/ye5NORhPyyUlL5p664Qf5Q7EGlSgLfK7cFnNqTQDbGiY6+xOqvIrNKCf9kUhkkUOaAh4DvQWzoG5HAnoBYNaTgcZif9uFIoqvh42JQMW0iirAYaASICncgBNHzOFowiqZotjNFs1KBkalm4Tf6uY9gZaGAsA9bFvjdR0uFwRsswFI7DTzuE=" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=debug msg="completed challenge" Feb 07 19:16:06 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:07 volumio-stefan volumio[5666]: info: Initializing connection to go-librespot Websocket Feb 07 19:16:07 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:07+02:00" level=debug msg="new websocket client" Feb 07 19:16:07 volumio-stefan volumio[5666]: info: Connection to go-librespot Websocket established Feb 07 19:16:07 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:07+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:16:07 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:07+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:07 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:07+02:00" level=debug msg="completed challenge" Feb 07 19:16:07 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:07+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:08 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:08+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:16:08 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:43018->104.199.65.9:80: read: connection reset by peer" Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 19:16:08 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 19:16:08 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:08+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 19:16:09 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:09+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:09 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:09+02:00" level=debug msg="completed challenge" Feb 07 19:16:09 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:09+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:09 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 19:16:09 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 19:16:09 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:09 volumio-stefan volumio[5666]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:09 volumio-stefan volumio[5666]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 19:16:09 volumio-stefan volumio[5666]: info: MyVolumio login type: Token Feb 07 19:16:09 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 19:16:09 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 19:16:09 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:09+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 07 19:16:10 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 19:16:10 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 19:16:10 volumio-stefan volumio[5666]: info: Streaming services startup Feb 07 19:16:10 volumio-stefan volumio[5666]: info: Starting Streaming Daemon Feb 07 19:16:10 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:10+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:16:10 volumio-stefan sudo[5901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 19:16:10 volumio-stefan sudo[5901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:10 volumio-stefan volumio[5666]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 19:16:10 volumio-stefan sudo[5901]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:10 volumio-stefan volumio[5666]: error: Cannot start Volumio Streaming Daemon Feb 07 19:16:10 volumio-stefan volumio[5666]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 19:16:10 volumio-stefan volumio[5666]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 19:16:10 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:10+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:10 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:10+02:00" level=debug msg="completed challenge" Feb 07 19:16:10 volumio-stefan volumio[5666]: info: Getting Spotify volume Feb 07 19:16:10 volumio-stefan volumio[5666]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 07 19:16:10 volumio-stefan volumio[5666]: info: CoreCommandRouter::volumioGetState Feb 07 19:16:10 volumio-stefan volumio[5666]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:10 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:10+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:10 volumio-stefan volumio[5666]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 19:16:11 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:11+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:16:11 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:11+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:38940->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:16:11 volumio-stefan go-librespot[5891]: time="2026-02-07T19:16:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:38940->104.199.65.9:4070: read: connection reset by peer" Feb 07 19:16:11 volumio-stefan volumio[5666]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:16:11 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:11 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:16:11 volumio-stefan volumio[5666]: Error: socket hang up Feb 07 19:16:11 volumio-stefan volumio[5666]: at connResetException (node:internal/errors:720:14) Feb 07 19:16:11 volumio-stefan volumio[5666]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 19:16:11 volumio-stefan volumio[5666]: at Socket.emit (node:events:526:35) Feb 07 19:16:11 volumio-stefan volumio[5666]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 19:16:11 volumio-stefan volumio[5666]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 19:16:11 volumio-stefan volumio[5666]: code: 'ECONNRESET', Feb 07 19:16:11 volumio-stefan volumio[5666]: response: undefined Feb 07 19:16:11 volumio-stefan volumio[5666]: } Feb 07 19:16:11 volumio-stefan volumio[5666]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:16:11 volumio-stefan sudo[5936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 19:15' Feb 07 19:16:11 volumio-stefan sudo[5936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:12 volumio-stefan sudo[5936]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:12 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:16:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 19:16:12 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:16:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 19:16:12 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:12 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 19:16:12 volumio-stefan systemd[1]: volumio.service: Consumed 25.112s CPU time. Feb 07 19:16:12 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 19:16:12 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 19:16:12 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9453. Feb 07 19:16:12 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 19:16:12 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 19:16:12 volumio-stefan systemd[1]: volumio.service: Consumed 25.112s CPU time. Feb 07 19:16:12 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 19:16:12 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 19:16:12 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28829. Feb 07 19:16:12 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:16:13 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:16:13 volumio-stefan upmpdcli[5963]: Could not open config: /tmp/upmpdcli.conf Feb 07 19:16:13 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:13 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 19:16:14 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:14 volumio-stefan volumio[5948]: info: ----- Volumio3 ---- Feb 07 19:16:14 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:14 volumio-stefan volumio[5948]: info: ----- System startup ---- Feb 07 19:16:14 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:14 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 19:16:14 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:14 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:14 volumio-stefan go-librespot[5970]: go-librespot daemon starting... Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02:00" level=debug msg="app state loaded" Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02: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]" Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02: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]" Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02: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]" Feb 07 19:16:14 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:14+02:00" level=info msg="zeroconf server listening on port 41575" Feb 07 19:16:15 volumio-stefan volumio[5948]: info: MYVOLUMIO Environment detected Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=debug msg="obtained new client token: AACz4dq5fp4JIa4XMA6v64hgk+L6sOWd8Crh3t4MCJBoRSEJ0lHUvnjK0SukG+kznFApztUnVssk4T6UxTBusvLzvMX1pqz7ViLEC+PFgh4uROxBNAYpKbt1lBoYVYChcpHC8kif5Se2uaBuXW+o8GcL5LX47FVCL/L2oC/FXLn9T376gTi/mn6Exl9jauA5M7PcKzP//6w9zdb8IJWvKaOq+1/lNQnPKGoI1JwCpoKYcwr7xtbu" Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Plugin folders cleanup Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning into folder /volumio/app/plugins/ Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category audio_interface Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category miscellanea Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category music_service Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category plugins.json Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category system_controller Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category user_interface Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning into folder /data/plugins/ Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category music_service Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category system_controller Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Scanning category user_interface Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Plugin folders cleanup completed Feb 07 19:16:15 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:15 volumio-stefan volumio[5948]: info: ----- Core plugins startup ---- Feb 07 19:16:15 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Adding plugin upnp to MyMusic Plugins Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Loading plugins from folder /data/plugins/ Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Loading plugin "system"... Feb 07 19:16:15 volumio-stefan volumio[5948]: info: Loading plugin "appearance"... Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=debug msg="completed challenge" Feb 07 19:16:15 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:15+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "network"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Refreshing Cached IP Addresses Feb 07 19:16:16 volumio-stefan sudo[5988]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 19:16:16 volumio-stefan sudo[5988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:16 volumio-stefan sudo[5990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 19:16:16 volumio-stefan sudo[5990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:16 volumio-stefan sudo[5988]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:16 volumio-stefan sudo[5990]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "services"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "alsa_controller"... Feb 07 19:16:16 volumio-stefan sudo[6003]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 19:16:16 volumio-stefan sudo[6003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:16 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "wizard"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "networkfs"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Starting Udev Watcher for removable devices Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Ignoring mount for partition: boot Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Ignoring mount for partition: volumio Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Ignoring mount for partition: volumio_data Feb 07 19:16:16 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "volumio_command_line_client"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Plugin upnp is not enabled Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "my_music"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "mpd"... Feb 07 19:16:16 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Plugin upnp_browser is not enabled Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "alarm-clock"... Feb 07 19:16:16 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:16+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:16 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:16+02:00" level=debug msg="completed challenge" Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Plugin airplay_emulation is not enabled Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "last_100"... Feb 07 19:16:16 volumio-stefan volumio[5948]: info: Loading plugin "webradio"... Feb 07 19:16:16 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:17 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:16:17] [connect] Successful connection Feb 07 19:16:17 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:17+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 19:16:17 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:17+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:17 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:17+02:00" level=debug msg="completed challenge" Feb 07 19:16:17 volumio-stefan volumio[5948]: info: Loading plugin "i2s_dacs"... Feb 07 19:16:17 volumio-stefan volumio[5948]: info: Loading plugin "volumiodiscovery"... Feb 07 19:16:18 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:18+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:18 volumio-stefan volumio[5948]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:16:18 volumio-stefan volumio[5948]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:16:18 volumio-stefan volumio[5948]: *** WARNING *** For more information see Feb 07 19:16:18 volumio-stefan volumio[5948]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:16:18 volumio-stefan volumio[5948]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:16:18 volumio-stefan volumio[5948]: *** WARNING *** For more information see Feb 07 19:16:18 volumio-stefan node[5948]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 19:16:18 volumio-stefan node[5948]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:16:18 volumio-stefan node[5948]: *** WARNING *** For more information see Feb 07 19:16:18 volumio-stefan node[5948]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 19:16:18 volumio-stefan node[5948]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 19:16:18 volumio-stefan node[5948]: *** WARNING *** For more information see Feb 07 19:16:18 volumio-stefan volumio[5948]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 19:16:18 volumio-stefan volumio[5948]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 19:16:18 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 19:16:18 volumio-stefan volumio[5948]: info: Loading plugin "spop"... Feb 07 19:16:18 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 19:16:18 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:18+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:18 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:18+02:00" level=debug msg="completed challenge" Feb 07 19:16:19 volumio-stefan volumio[5948]: info: Loading plugin "now_playing"... Feb 07 19:16:19 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:19+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:19 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:19+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "outputs"... Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "albumart"... Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Plugin example_plugin is not enabled Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "inputs"... Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "updater_comm"... Feb 07 19:16:20 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:20+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:20 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:20+02:00" level=debug msg="completed challenge" Feb 07 19:16:20 volumio-stefan sudo[6003]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Plugin mpdemulation is not enabled Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "rest_api"... Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "websocket"... Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Starting Socket.io Server version 1.7.4 Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "backup_restore"... Feb 07 19:16:20 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:20+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:20 volumio-stefan go-librespot[5971]: time="2026-02-07T19:16:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:20 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:20 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Applying required configuration parameters for plugin backup_restore Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading plugin "Systeminfo"... Feb 07 19:16:20 volumio-stefan volumio[6020]: Forking 3 albumart workers Feb 07 19:16:20 volumio-stefan volumio[5948]: info: Loading i18n strings for locale en Feb 07 19:16:20 volumio-stefan volumio[5948]: Updating browse sources language Feb 07 19:16:20 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::initPlayerControls Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: Express server listening on port 3000 Feb 07 19:16:21 volumio-stefan volumio[5948]: [Metrics] WebUI: 7s 287.38ms Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::resetVolumioState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::getcurrentVolume Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::pushState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioPushState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Volumio Network Manager: Network status updated: 2 Feb 07 19:16:21 volumio-stefan volumio-remote-updater[658]: [2026-02-07 19:16:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770484577 101 Feb 07 19:16:21 volumio-stefan volumio[5948]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Reloading queue from file Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::setRepeat null single undefined Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::pushState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioPushState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::setRandom null Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreStateMachine::pushState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioPushState Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Setting Device type: Raspberry PI Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Completed loading Core Plugins Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Preparing to generate the ALSA configuration file Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Asound.conf file unchanged, so no further update is needed Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Output device has changed, restarting MPD Feb 07 19:16:21 volumio-stefan volumio[5948]: info: ___________ START PLUGINS ___________ Feb 07 19:16:21 volumio-stefan volumio[5948]: info: ControllerMpd::onStart: Initializing MPD Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Creating MPD Configuration file Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:16:21 volumio-stefan volumio[5948]: info: [1770484581565] CoreMusicLibrary::Adding element Last_100 Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:16:21 volumio-stefan sudo[6071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:16:21 volumio-stefan sudo[6071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:21 volumio-stefan sudo[6072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:16:21 volumio-stefan sudo[6072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:21 volumio-stefan sudo[6071]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 19:16:21 volumio-stefan volumio[5948]: info: [1770484581584] CoreMusicLibrary::Adding element Webradio Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:16:21 volumio-stefan sudo[6074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 19:16:21 volumio-stefan sudo[6074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Initializing BBC Radios Feb 07 19:16:21 volumio-stefan sudo[6074]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:21 volumio-stefan sudo[6076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 19:16:21 volumio-stefan sudo[6076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:21 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 19:16:21 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 19:16:21 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 19:16:21 volumio-stefan systemd[1]: mpd.service: Consumed 3.371s CPU time. Feb 07 19:16:21 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 19:16:21 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 19:16:21 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:21 volumio-stefan volumio[5948]: info: Creating Spotify config file Feb 07 19:16:21 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:21 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 19:16:21 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 19:16:22 volumio-stefan sudo[6095]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 19:16:22 volumio-stefan sudo[6095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 19:16:22 volumio-stefan sudo[6095]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:22 volumio-stefan volumio[5948]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Volumio Calling Home Feb 07 19:16:22 volumio-stefan volumio[6030]: Starting albumart workers Feb 07 19:16:22 volumio-stefan volumio[6031]: Starting albumart workers Feb 07 19:16:22 volumio-stefan volumio[6032]: Starting albumart workers Feb 07 19:16:22 volumio-stefan volumio[5948]: info: [now-playing] App is listening on port 4004. Feb 07 19:16:22 volumio-stefan volumio[5948]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Discovery: Found device Volumio Stefan Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioGetState Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Discovery: Found device Volumio Stefan Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioGetState Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:22 volumio-stefan volumio[5948]: info: MPD Permissions set Feb 07 19:16:22 volumio-stefan volumio[5948]: info: MPD Permissions set Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Spotify config file written Feb 07 19:16:22 volumio-stefan volumio[5948]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 19:16:22 volumio-stefan volumio[5948]: info: Volumio called home Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan sudo[6102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 19:16:22 volumio-stefan sudo[6102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 19:16:22 volumio-stefan volumio[5948]: info: No need to fix Spotify hosts Feb 07 19:16:22 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:22 volumio-stefan go-librespot[6115]: go-librespot daemon starting... Feb 07 19:16:22 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:22 volumio-stefan sudo[6102]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:22 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:22+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:16:22 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:22+02:00" level=debug msg="app state loaded" Feb 07 19:16:22 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:16:23 volumio-stefan volumio[5948]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02: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]" Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02: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]" Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02: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]" Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02:00" level=info msg="zeroconf server listening on port 36515" Feb 07 19:16:23 volumio-stefan volumio[5948]: info: CoreCommandRouter::volumioGetState Feb 07 19:16:23 volumio-stefan volumio[5948]: info: CorePlayQueue::getTrack 0 Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02:00" level=debug msg="obtained new client token: AAC1o5Qh/eipd63MFyWseTESOx8WMfQCfQtmi9ythb/rRbCRzT0lOUMDgUWK4rlcRR4cExYisYfHxj21b0cAbr5nDRDkxm6IEQOESlVDNK0MFGbNUcOjUfJgmCT4yqIhCiADkojLiVvN5ZXAb/wBUw47fw9cErIltntEyQ5TnfSq9ctXrcTjnhOdh+r+YKDD2f1Jy/swGnz7O4hg5Z8iCBa2hQ0TiUoPwqqBViAG2gSPT0ZDgfx3VMU=" Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:16:23 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 07 19:16:24 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:24+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:16:24 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:24+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:40080->104.199.65.9:443: read: connection reset by peer" Feb 07 19:16:24 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:24+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:16:24 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:24+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:54580->104.199.65.9:80: read: connection reset by peer" Feb 07 19:16:25 volumio-stefan mpd[6097]: 2026-02-07T19:16:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 19:16:25 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 19:16:25 volumio-stefan sudo[6076]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:25 volumio-stefan sudo[6072]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:25 volumio-stefan volumio[5948]: info: Completed starting Core Plugins Feb 07 19:16:25 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:25 volumio-stefan volumio[5948]: info: ----- MyVolumio plugins startup ---- Feb 07 19:16:25 volumio-stefan volumio[5948]: info: ------------------------------------------- Feb 07 19:16:25 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 19:16:25 volumio-stefan volumio[5948]: error: MPD error: The expression evaluated to a falsy value: Feb 07 19:16:25 volumio-stefan volumio[5948]: assert.ok(self.idling) Feb 07 19:16:25 volumio-stefan volumio[5948]: error: The expression evaluated to a falsy value: Feb 07 19:16:25 volumio-stefan volumio[5948]: assert.ok(self.idling) Feb 07 19:16:25 volumio-stefan volumio[5948]: error: updateQueue error: null Feb 07 19:16:25 volumio-stefan volumio[5948]: info: MPD running with PID6097 Feb 07 19:16:25 volumio-stefan volumio[5948]: ,establishing connection Feb 07 19:16:25 volumio-stefan volumio[5948]: error: updateQueue error: null Feb 07 19:16:25 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:25+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 19:16:25 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:25+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 19:16:25 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:25+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:25 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:25+02:00" level=debug msg="completed challenge" Feb 07 19:16:25 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:25+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:26 volumio-stefan volumio[5948]: info: go-librespot daemon successfully initialized Feb 07 19:16:26 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:26+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 07 19:16:26 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:26+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Feb 07 19:16:26 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:16:26 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:26+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:40082->104.199.65.9:443: read: connection reset by peer" Feb 07 19:16:27 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:27+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:16:27 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:27+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:54588->104.199.65.9:80: read: connection reset by peer" Feb 07 19:16:27 volumio-stefan go-librespot[6116]: time="2026-02-07T19:16:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:54588->104.199.65.9:80: read: connection reset by peer" Feb 07 19:16:27 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:27 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:16:28 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28830. Feb 07 19:16:28 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:16:28 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 19:16:28 volumio-stefan upmpdcli[6162]: Could not open config: /tmp/upmpdcli.conf Feb 07 19:16:28 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:28 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 19:16:29 volumio-stefan volumio[5948]: info: Initializing connection to go-librespot Websocket Feb 07 19:16:29 volumio-stefan volumio[5948]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 19:16:30 volumio-stefan volumio[5948]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 19:16:30 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 19:16:30 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:30 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 19:16:30 volumio-stefan go-librespot[6163]: go-librespot daemon starting... Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02:00" level=debug msg="app state loaded" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02: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]" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02: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]" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02: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]" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02:00" level=info msg="zeroconf server listening on port 38447" Feb 07 19:16:30 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:30+02:00" level=debug msg="obtained new client token: AAAg+RxKjgYIwdqYdf/Ih4utBgdkOzZEJA4Y01yJa9hqtcX9aDSaj5k//sUSDjlLvmB8xlLSRS3oiBWQ1mcJw+eNkedP3WoXcKkJTcBvlmt5HwoDLU5y+HoHP9h7JVe8QrP4gEn3nIK9yARipdL1OQ7VuN7fht1Vb/nsIOwV4mmE9fSiu+cWBhEwsuNpevzSe2l1VMKN/474rpF6n6W71HYX8WQqdgobB3BcmI4yDoAojaAs2OWNoFo=" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=debug msg="completed challenge" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=debug msg="completed challenge" Feb 07 19:16:31 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:32 volumio-stefan volumio[5948]: info: Initializing connection to go-librespot Websocket Feb 07 19:16:32 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:32+02:00" level=debug msg="new websocket client" Feb 07 19:16:32 volumio-stefan volumio[5948]: info: Connection to go-librespot Websocket established Feb 07 19:16:32 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:32+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 19:16:32 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:32+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:32 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:32+02:00" level=debug msg="completed challenge" Feb 07 19:16:32 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:32+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:33 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:33+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 19:16:33 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 19:16:33 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:33+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:33 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:33+02:00" level=debug msg="completed challenge" Feb 07 19:16:33 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:33+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:34 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 19:16:34 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:34+02:00" level=debug msg="completed keyexchange" Feb 07 19:16:34 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:34+02:00" level=debug msg="completed challenge" Feb 07 19:16:34 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 19:16:34 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 19:16:34 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:34 volumio-stefan volumio[5948]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 19:16:34 volumio-stefan volumio[5948]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 19:16:34 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:34+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 19:16:34 volumio-stefan volumio[5948]: info: MyVolumio login type: Token Feb 07 19:16:34 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 19:16:34 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 19:16:35 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:35+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Feb 07 19:16:35 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:35+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 19:16:35 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:35+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:53904->104.199.65.9:443: read: connection reset by peer" Feb 07 19:16:35 volumio-stefan go-librespot[6164]: time="2026-02-07T19:16:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.4:53904->104.199.65.9:443: read: connection reset by peer" Feb 07 19:16:35 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 19:16:35 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 19:16:35 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 19:16:35 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 19:16:35 volumio-stefan volumio[5948]: info: Streaming services startup Feb 07 19:16:35 volumio-stefan volumio[5948]: info: Starting Streaming Daemon Feb 07 19:16:35 volumio-stefan sudo[6175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 19:16:35 volumio-stefan sudo[6175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 19:16:35 volumio-stefan volumio[5948]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 19:16:35 volumio-stefan sudo[6175]: pam_unix(sudo:session): session closed for user root Feb 07 19:16:35 volumio-stefan volumio[5948]: info: Getting Spotify volume Feb 07 19:16:35 volumio-stefan volumio[5948]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:16:35 volumio-stefan volumio[5948]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 19:16:35 volumio-stefan volumio[5948]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 19:16:35 volumio-stefan volumio[5948]: errno: -111, Feb 07 19:16:35 volumio-stefan volumio[5948]: code: 'ECONNREFUSED', Feb 07 19:16:35 volumio-stefan volumio[5948]: syscall: 'connect', Feb 07 19:16:35 volumio-stefan volumio[5948]: address: '127.0.0.1', Feb 07 19:16:35 volumio-stefan volumio[5948]: port: 9879, Feb 07 19:16:35 volumio-stefan volumio[5948]: response: undefined Feb 07 19:16:35 volumio-stefan volumio[5948]: } Feb 07 19:16:35 volumio-stefan volumio[5948]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 19:16:36 volumio-stefan sudo[6196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 19:15' Feb 07 19:16:36 volumio-stefan sudo[6196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"