Feb 09 04:54:00 volumio volumio-remote-updater[643]: [2026-02-09 04:54:00] [connect] Successful connection Feb 09 04:54:00 volumio volumio[27447]: info: MYVOLUMIO Environment detected Feb 09 04:54:00 volumio volumio[27447]: info: Plugin folders cleanup Feb 09 04:54:00 volumio volumio[27447]: info: Scanning into folder /volumio/app/plugins/ Feb 09 04:54:00 volumio volumio[27447]: info: Scanning category audio_interface Feb 09 04:54:00 volumio volumio[27447]: info: Scanning category miscellanea Feb 09 04:54:00 volumio volumio[27447]: info: Scanning category music_service Feb 09 04:54:00 volumio volumio[27447]: info: Scanning category plugins.json Feb 09 04:54:00 volumio volumio[27447]: info: Scanning category system_controller Feb 09 04:54:00 volumio volumio[27447]: info: Scanning category user_interface Feb 09 04:54:01 volumio volumio[27447]: info: Scanning into folder /data/plugins/ Feb 09 04:54:01 volumio volumio[27447]: info: Scanning category music_service Feb 09 04:54:01 volumio volumio[27447]: info: Plugin folders cleanup completed Feb 09 04:54:01 volumio volumio[27447]: info: ------------------------------------------- Feb 09 04:54:01 volumio volumio[27447]: info: ----- Core plugins startup ---- Feb 09 04:54:01 volumio volumio[27447]: info: ------------------------------------------- Feb 09 04:54:01 volumio volumio[27447]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 04:54:01 volumio volumio[27447]: info: Adding plugin upnp to MyMusic Plugins Feb 09 04:54:01 volumio volumio[27447]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 04:54:01 volumio volumio[27447]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 04:54:01 volumio volumio[27447]: info: Loading plugins from folder /data/plugins/ Feb 09 04:54:01 volumio volumio[27447]: info: Loading plugin "system"... Feb 09 04:54:01 volumio volumio[27447]: info: Loading plugin "appearance"... Feb 09 04:54:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 09 04:54:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:02 volumio go-librespot[27487]: go-librespot daemon starting... Feb 09 04:54:02 volumio go-librespot[27488]: time="2026-02-09T04:54:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:02 volumio go-librespot[27488]: time="2026-02-09T04:54:02+07:00" level=debug msg="app state loaded" Feb 09 04:54:02 volumio go-librespot[27488]: time="2026-02-09T04:54:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:02 volumio volumio[27447]: info: Loading plugin "network"... Feb 09 04:54:03 volumio volumio[27447]: info: Refreshing Cached IP Addresses Feb 09 04:54:03 volumio sudo[27496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:54:03 volumio sudo[27496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:03 volumio sudo[27498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:54:03 volumio sudo[27496]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:03 volumio sudo[27498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:03 volumio sudo[27498]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "services"... Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "alsa_controller"... Feb 09 04:54:03 volumio sudo[27507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 04:54:03 volumio sudo[27507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=info msg="zeroconf server listening on port 39595" Feb 09 04:54:03 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "wizard"... Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "networkfs"... Feb 09 04:54:03 volumio volumio[27447]: info: Starting Udev Watcher for removable devices Feb 09 04:54:03 volumio volumio[27447]: info: Ignoring mount for partition: boot Feb 09 04:54:03 volumio volumio[27447]: info: Ignoring mount for partition: volumio Feb 09 04:54:03 volumio volumio[27447]: info: Ignoring mount for partition: volumio_data Feb 09 04:54:03 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "volumio_command_line_client"... Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "upnp"... Feb 09 04:54:03 volumio volumio[27447]: info: [1770587643429] Starting Upmpd Daemon Feb 09 04:54:03 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "my_music"... Feb 09 04:54:03 volumio volumio[27447]: info: Loading plugin "mpd"... Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="obtained new client token: AACaALJBgTtZPmPjlJXOT9+gZi4/gry+xPonjBmHIzVQQ3Qc728dOtopPgBtjIZM77L624kDsP3BqvM9yC1spIExbHYowh8md9n4oDedoTD0Z+YcECaS44pIjZUbVLOM75VOcFN033j2x+TeG1Su9bNB4hBmIAXX5eY1pnfgi4Gp11NUWj50TCf6V9M6fdh/wiTFZTkqHpo9YoB6ekHHNoA2IQ39Qj38F7fTAFjXD3NrR9BYwixiHC8B1g==" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07:00" level=debug msg="completed challenge" Feb 09 04:54:03 volumio go-librespot[27488]: time="2026-02-09T04:54:03+07: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 09 04:54:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:04 volumio volumio[27447]: info: Loading plugin "upnp_browser"... Feb 09 04:54:05 volumio sudo[27507]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 09 04:54:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:06 volumio go-librespot[27529]: go-librespot daemon starting... Feb 09 04:54:06 volumio go-librespot[27530]: time="2026-02-09T04:54:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:06 volumio go-librespot[27530]: time="2026-02-09T04:54:06+07:00" level=debug msg="app state loaded" Feb 09 04:54:06 volumio go-librespot[27530]: time="2026-02-09T04:54:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:07 volumio volumio[27447]: info: Starting UPNP Browser Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "alarm-clock"... Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "airplay_emulation"... Feb 09 04:54:07 volumio volumio[27447]: info: Starting Shairport Sync Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "last_100"... Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "webradio"... Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=info msg="zeroconf server listening on port 42891" Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "i2s_dacs"... Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "volumiodiscovery"... Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="obtained new client token: AABqhOJ9GIXoimxbJ56ciNM0uGULAH7UX8so39+1xwTlEwr31c1CtoxbAUaMlJE6WA9EmY+BXsK4sb4JCkFTpw5+bojP5ELEngfVetsPdTdUjWx4F4oxBaHezONcEzR7rLcjHpQTdMunlChaNJbD1nfikg8YVjTfTRVdn3eGhnpeGvgFPY7lk0bhM2l0gjech+xUROJLo8FhJqlhWOXzdrKarARdiwDc5xtdAjiS9WKyklsY5+IPZzz3IQ==" Feb 09 04:54:07 volumio volumio[27447]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:54:07 volumio volumio[27447]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:54:07 volumio volumio[27447]: *** WARNING *** For more information see Feb 09 04:54:07 volumio node[27447]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:54:07 volumio volumio[27447]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:54:07 volumio volumio[27447]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:54:07 volumio volumio[27447]: *** WARNING *** For more information see Feb 09 04:54:07 volumio node[27447]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:54:07 volumio node[27447]: *** WARNING *** For more information see Feb 09 04:54:07 volumio node[27447]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:54:07 volumio node[27447]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:54:07 volumio node[27447]: *** WARNING *** For more information see Feb 09 04:54:07 volumio volumio[27447]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 04:54:07 volumio volumio[27447]: info: Discovery: Started advertising with name: Volumio Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:07 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:54:07 volumio volumio[27447]: info: Loading plugin "spop"... Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07:00" level=debug msg="completed challenge" Feb 09 04:54:07 volumio go-librespot[27530]: time="2026-02-09T04:54:07+07: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 09 04:54:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:09 volumio volumio[27447]: info: Loading plugin "ytcr"... Feb 09 04:54:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 09 04:54:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:11 volumio go-librespot[27539]: go-librespot daemon starting... Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=debug msg="app state loaded" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=info msg="zeroconf server listening on port 34799" Feb 09 04:54:11 volumio go-librespot[27540]: time="2026-02-09T04:54:11+07:00" level=debug msg="obtained new client token: AAAEzTLkJi0GZ7ciGHbUEGtKdZ6M9ql5DcK0q9b2tJOH9uxqhN42YIR4JfFUhpTnXrJu0zsoWRnTWukC5x24grN4+VTkbTTe7tMlmYMxaL8yw/9JeuHPSbP3Cn8Cy0yzu+RkuHX3c/t7IncKGpEKI+SY/WuFGfIfnL3WVyUd3TMdD++EtKfTA1620PDghfw4WQJi9cUtJiC6z2JD4P1cegNHGTI/ma6AsY8DlE5tUCA1hhRwNk3ZXH6DSQ==" Feb 09 04:54:12 volumio go-librespot[27540]: time="2026-02-09T04:54:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:12 volumio go-librespot[27540]: time="2026-02-09T04:54:12+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:12 volumio go-librespot[27540]: time="2026-02-09T04:54:12+07:00" level=debug msg="completed challenge" Feb 09 04:54:12 volumio go-librespot[27540]: time="2026-02-09T04:54:12+07: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 09 04:54:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:12 volumio volumio[27447]: info: Loading plugin "ytmusic"... Feb 09 04:54:13 volumio volumio-remote-updater[643]: [2026-02-09 04:54:13] [connect] Successful connection Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "outputs"... Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "albumart"... Feb 09 04:54:13 volumio volumio[27447]: info: Plugin example_plugin is not enabled Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "inputs"... Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "updater_comm"... Feb 09 04:54:13 volumio volumio[27447]: info: Plugin mpdemulation is not enabled Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "rest_api"... Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "websocket"... Feb 09 04:54:13 volumio volumio[27447]: info: Starting Socket.io Server version 1.7.4 Feb 09 04:54:13 volumio volumio[27447]: info: Loading plugin "RoonBridge"... Feb 09 04:54:14 volumio volumio[27447]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 04:54:14 volumio volumio[27447]: info: Loading i18n strings for locale en Feb 09 04:54:14 volumio volumio[27447]: Updating browse sources language Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:54:14 volumio volumio[27562]: Forking 3 albumart workers Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::initPlayerControls Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:54:14 volumio volumio[27447]: Express server listening on port 3000 Feb 09 04:54:14 volumio volumio[27447]: [Metrics] WebUI: 16s 16.65ms Feb 09 04:54:14 volumio volumio[27447]: info: CoreStateMachine::resetVolumioState Feb 09 04:54:14 volumio volumio[27447]: info: CoreStateMachine::getcurrentVolume Feb 09 04:54:14 volumio volumio[27447]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:54:14 volumio sudo[27607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:54:14 volumio sudo[27607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:14 volumio volumio[27447]: info: Volumio Network Manager: Network status updated: 1 Feb 09 04:54:14 volumio sudo[27607]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:14 volumio sudo[27609]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:54:14 volumio sudo[27609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:14 volumio sudo[27609]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:15 volumio volumio[27447]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::pushState Feb 09 04:54:15 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::volumioPushState Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::updateTrackBlock Feb 09 04:54:15 volumio volumio[27447]: info: CorePlayQueue::getTrackBlock Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:54:15 volumio volumio-remote-updater[643]: [2026-02-09 04:54:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770587653 101 Feb 09 04:54:15 volumio volumio[27447]: 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 09 04:54:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 09 04:54:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:15 volumio volumio[27447]: info: Reloading queue from file Feb 09 04:54:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:15 volumio go-librespot[27619]: go-librespot daemon starting... Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::setRepeat null single undefined Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::pushState Feb 09 04:54:15 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::volumioPushState Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::setRandom null Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::pushState Feb 09 04:54:15 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::volumioPushState Feb 09 04:54:15 volumio volumio[27447]: info: Setting Device type: Raspberry PI Feb 09 04:54:15 volumio go-librespot[27621]: time="2026-02-09T04:54:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:15 volumio go-librespot[27621]: time="2026-02-09T04:54:15+07:00" level=debug msg="app state loaded" Feb 09 04:54:15 volumio go-librespot[27621]: time="2026-02-09T04:54:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:15 volumio volumio[27447]: info: Completed loading Core Plugins Feb 09 04:54:15 volumio volumio[27447]: info: Preparing to generate the ALSA configuration file Feb 09 04:54:15 volumio volumio[27447]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:54:15 volumio volumio[27447]: info: CoreStateMachine::pushState Feb 09 04:54:15 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::volumioPushState Feb 09 04:54:15 volumio volumio[27447]: info: Asound.conf file unchanged, so no further update is needed Feb 09 04:54:15 volumio volumio[27447]: info: Output device has changed, restarting MPD Feb 09 04:54:15 volumio sudo[27632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:54:15 volumio sudo[27632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:15 volumio volumio[27447]: info: Output device has changed, restarting Shairport Sync Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:15 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:15 volumio sudo[27632]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:15 volumio sudo[27630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 04:54:15 volumio sudo[27630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:15 volumio sudo[27634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:54:15 volumio sudo[27634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:15 volumio volumio[27447]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:54:15 volumio volumio[27447]: info: ___________ START PLUGINS ___________ Feb 09 04:54:15 volumio volumio[27447]: info: ControllerMpd::onStart: Initializing MPD Feb 09 04:54:15 volumio volumio[27447]: info: Creating MPD Configuration file Feb 09 04:54:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 04:54:16 volumio sudo[27630]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:54:16 volumio volumio[27447]: info: [1770587656105] CoreMusicLibrary::Adding element Media Servers Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:16 volumio sudo[27645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:54:16 volumio sudo[27645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:16 volumio sudo[27645]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=info msg="zeroconf server listening on port 38393" Feb 09 04:54:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:54:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:54:16 volumio systemd[1]: mpd.service: Consumed 7.278s CPU time. Feb 09 04:54:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:54:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:54:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:54:16 volumio sudo[27647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:54:16 volumio volumio[27447]: info: UPNP Browser: Client initialized successfully Feb 09 04:54:16 volumio sudo[27647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:54:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:54:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="obtained new client token: AAByySeiZZkJ/Bgk3YOJWK36VLSrP/z8dkUWiHq+wYnPrSnYTowsaDyOgyyqfxaQd0+mKs3XP80GYZnKIQ92pi78IFDeDYMcsYdKN68hRyw6+dVu79ld2lF+Vzj3KKPAlX0l1fg+cuO34ErlFBaVPbe86WBOj6YP2VdHioMp7a5vbIPmxjXpYV0+p53ZZKDQR9w5SfAoPKvHIYXRPE/6UApwGXjELOAO0MdYruVNrZAhSrYLdMrD089RnA==" Feb 09 04:54:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:54:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:54:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:54:16 volumio volumio[27447]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:54:16 volumio volumio[27447]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:54:16 volumio volumio[27447]: info: [1770587656525] CoreMusicLibrary::Adding element Last_100 Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:54:16 volumio volumio[27447]: info: [1770587656549] CoreMusicLibrary::Adding element Webradio Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:54:16 volumio volumio[27447]: info: Initializing BBC Radios Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07:00" level=debug msg="completed challenge" Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:16 volumio go-librespot[27621]: time="2026-02-09T04:54:16+07: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 09 04:54:16 volumio volumio[27447]: info: Creating Spotify config file Feb 09 04:54:16 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:17 volumio sudo[27661]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 04:54:17 volumio sudo[27661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 04:54:17 volumio sudo[27661]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:17 volumio volumio[27572]: Starting albumart workers Feb 09 04:54:17 volumio volumio[27447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:54:17 volumio volumio[27447]: info: [1770587657845] CoreMusicLibrary::Adding element YouTube Music Feb 09 04:54:17 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:54:17 volumio volumio[27447]: Cannot find translation for source YouTube Music Feb 09 04:54:17 volumio volumio[27573]: Starting albumart workers Feb 09 04:54:17 volumio volumio[27447]: info: Volumio Calling Home Feb 09 04:54:17 volumio sudo[27678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 04:54:17 volumio sudo[27678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:18 volumio sudo[27678]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:18 volumio volumio[27574]: Starting albumart workers Feb 09 04:54:18 volumio volumio[27447]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:54:18 volumio volumio[27447]: info: Discovery: Found device Volumio Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::volumioGetState Feb 09 04:54:18 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:18 volumio volumio[27447]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:54:18 volumio volumio[27447]: info: Discovery: Found device Volumio Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::volumioGetState Feb 09 04:54:18 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:18 volumio volumio[27447]: info: MPD Permissions set Feb 09 04:54:18 volumio volumio[27447]: info: MPD Permissions set Feb 09 04:54:18 volumio volumio[27447]: info: Upmpdcli Daemon Started Feb 09 04:54:18 volumio volumio[27447]: info: Volumio called home Feb 09 04:54:18 volumio volumio[27447]: info: Spotify config file written Feb 09 04:54:18 volumio volumio[27447]: 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 09 04:54:18 volumio sudo[27685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 04:54:18 volumio sudo[27685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:18 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:54:19 volumio volumio[27447]: info: No need to fix Spotify hosts Feb 09 04:54:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:19 volumio go-librespot[27697]: go-librespot daemon starting... Feb 09 04:54:19 volumio sudo[27685]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:19 volumio go-librespot[27698]: time="2026-02-09T04:54:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:19 volumio go-librespot[27698]: time="2026-02-09T04:54:19+07:00" level=debug msg="app state loaded" Feb 09 04:54:19 volumio go-librespot[27698]: time="2026-02-09T04:54:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=info msg="zeroconf server listening on port 45091" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="obtained new client token: AAA+l3BXhTVXwZCA/Lh5+LcZ/u5GmWDfrmnOCTrXq1Y3fsSY7wJSHlbSeGLX0PO/KH2dYN/v1U8cpKx49bGMI4G7BwRAjuEAyAendccpGSlNSFNeDToFmNrtz5da+Nbhka2sOMwpBz+nmSkdpkPrOn71iUL1ydI01fp7HQtIO10a/myebWB61J1dnGNQnOoP59ab5X8L52kRs2aY83NPEZALFR2h7PY9SKYjwWjSebdQwJs9Zf+SJ40EzQ==" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:20 volumio volumio[27447]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:54:20 volumio volumio[27447]: SPOTIFY: BQDDWyCzV_P7BjkLo2qH0IMEsWgHcjHwrkeX4leq9lkqPWHqti6Hp4fghRTDQ_hSLUznI_l5wUbLRnAUyxL70TB1AM7eqf_r7Hhuy9JKsWYSETJAJIOjfGUj6mp0Il0GmouO0X1Vp39V8Sr5z9cGcU4jcguKo-__CDKU18ozzRCPUGL6gCGrTE1W11MQLHOb1bqXtN2Qc2IMOybj7U6wPFNY2L8t6kLGzlMoIwKB7JPSA_JK3lJM1F6TTtW4_ib0WxOfsFqHwqfaO6OwpLU_ea-jl1lGPd-Rjz1l_9KIwQtdAdBc4MqIuPIl Feb 09 04:54:20 volumio volumio[27447]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:54:20 volumio volumio[27447]: info: New Spotify access token = BQDDWyCzV_P7BjkLo2qH0IMEsWgHcjHwrkeX4leq9lkqPWHqti6Hp4fghRTDQ_hSLUznI_l5wUbLRnAUyxL70TB1AM7eqf_r7Hhuy9JKsWYSETJAJIOjfGUj6mp0Il0GmouO0X1Vp39V8Sr5z9cGcU4jcguKo-__CDKU18ozzRCPUGL6gCGrTE1W11MQLHOb1bqXtN2Qc2IMOybj7U6wPFNY2L8t6kLGzlMoIwKB7JPSA_JK3lJM1F6TTtW4_ib0WxOfsFqHwqfaO6OwpLU_ea-jl1lGPd-Rjz1l_9KIwQtdAdBc4MqIuPIl Feb 09 04:54:20 volumio volumio[27447]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 04:54:20 volumio volumio[27447]: info: Starting Shairport Sync Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07:00" level=debug msg="completed challenge" Feb 09 04:54:20 volumio volumio[27447]: info: Starting Shairport Sync Feb 09 04:54:20 volumio volumio[27447]: info: Starting Shairport Sync Feb 09 04:54:20 volumio sudo[27725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:54:20 volumio go-librespot[27698]: time="2026-02-09T04:54:20+07: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 09 04:54:20 volumio sudo[27725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:20 volumio sudo[27727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:54:20 volumio sudo[27727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:20 volumio sudo[27731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:54:20 volumio sudo[27731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:54:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:54:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:54:20 volumio systemd[1]: shairport-sync.service: Consumed 2.402s CPU time. Feb 09 04:54:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:54:21 volumio sudo[27727]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:21 volumio sudo[27731]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:21 volumio sudo[27725]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:21 volumio volumio[27447]: info: Shairport-Sync Started Feb 09 04:54:21 volumio volumio[27447]: Error adding Membership: Error: addMembership EINVAL Feb 09 04:54:21 volumio volumio[27447]: info: Shairport-Sync Started Feb 09 04:54:21 volumio volumio[27447]: info: Shairport-Sync Started Feb 09 04:54:21 volumio volumio[27447]: info: CoreCommandRouter::volumioGetState Feb 09 04:54:21 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:21 volumio volumio[27447]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 09 04:54:21 volumio volumio[27447]: info: Spotify Successfully logged in Feb 09 04:54:21 volumio volumio[27447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:54:21 volumio volumio[27447]: info: [1770587661351] CoreMusicLibrary::Adding element Spotify Feb 09 04:54:21 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:54:21 volumio volumio[27447]: Cannot find translation for source YouTube Music Feb 09 04:54:21 volumio volumio[27447]: Cannot find translation for source Spotify Feb 09 04:54:21 volumio volumio[27447]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 04:54:21 volumio volumio[27447]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:54:22 volumio volumio[27447]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:54:22 volumio volumio[27447]: info: CoreCommandRouter::volumioGetState Feb 09 04:54:22 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:22 volumio volumio[27447]: info: CoreStateMachine::pushState Feb 09 04:54:22 volumio volumio[27447]: info: CorePlayQueue::getTrack 0 Feb 09 04:54:22 volumio volumio[27447]: info: CoreCommandRouter::volumioPushState Feb 09 04:54:23 volumio volumio[27447]: info: go-librespot daemon successfully initialized Feb 09 04:54:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 09 04:54:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:23 volumio mpd[27676]: 2026-02-09T04:54:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 04:54:23 volumio go-librespot[27765]: go-librespot daemon starting... Feb 09 04:54:23 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 04:54:23 volumio sudo[27647]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:23 volumio sudo[27634]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:23 volumio go-librespot[27766]: time="2026-02-09T04:54:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:23 volumio go-librespot[27766]: time="2026-02-09T04:54:23+07:00" level=debug msg="app state loaded" Feb 09 04:54:23 volumio go-librespot[27766]: time="2026-02-09T04:54:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:24 volumio volumio[27447]: error: MPD error: The expression evaluated to a falsy value: Feb 09 04:54:24 volumio volumio[27447]: assert.ok(self.idling) Feb 09 04:54:24 volumio volumio[27447]: error: The expression evaluated to a falsy value: Feb 09 04:54:24 volumio volumio[27447]: assert.ok(self.idling) Feb 09 04:54:24 volumio volumio[27447]: info: MPD running with PID27676 Feb 09 04:54:24 volumio volumio[27447]: ,establishing connection Feb 09 04:54:24 volumio volumio[27447]: error: updateQueue error: null Feb 09 04:54:24 volumio volumio[27447]: info: Completed starting Core Plugins Feb 09 04:54:24 volumio volumio[27447]: info: ------------------------------------------- Feb 09 04:54:24 volumio volumio[27447]: info: ----- MyVolumio plugins startup ---- Feb 09 04:54:24 volumio volumio[27447]: info: ------------------------------------------- Feb 09 04:54:24 volumio volumio[27447]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 04:54:24 volumio volumio[27447]: error: updateQueue error: null Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=info msg="zeroconf server listening on port 42715" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="obtained new client token: AABfhUaGIjDxnb8tNfYWMYz9kSstmb1JcDW/VxZlgaR9+6b5XpaedmXyEt7/yOMz1H2LmfU7+XW5o5oM/O47FCOeoVB7+D9Q7pESECjjF0xkTojMAClE4o4vReierO1TKzgfQ0DXUsF3j/rQpNWISjw5i4F6+iAbB5aUPcOgvvhDhORJ+iJOfApdOg+ePyhhIf9o2QAF80HJmgujibz0v2B0mrEF3SGbrZvINEI3Z02Sy94mA/4PfkWqmg==" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:24 volumio go-librespot[27766]: time="2026-02-09T04:54:24+07:00" level=debug msg="completed challenge" Feb 09 04:54:25 volumio go-librespot[27766]: time="2026-02-09T04:54:25+07: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 09 04:54:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:26 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:26 volumio volumio[27447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 09 04:54:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:28 volumio go-librespot[27779]: go-librespot daemon starting... Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=debug msg="app state loaded" Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:28 volumio go-librespot[27780]: time="2026-02-09T04:54:28+07:00" level=info msg="zeroconf server listening on port 41127" Feb 09 04:54:28 volumio volumio[27447]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:54:29 volumio go-librespot[27780]: time="2026-02-09T04:54:29+07:00" level=debug msg="obtained new client token: AACSkhOsuq4wkDDfd3K30iiJfPCk88p+kDsMWN4nzPRvqMclXArCkMmWBtBDJGBjjfbnU95Kr2+YdU0PeD8h/FMw4hNYroAvNTnrbBwFkaIlF45EsB3jh5oRMTpj/sZv1SzOfa3jEb5nrcND0c+Upr21k2fDRzCHIprT7RdUsWgwfjOhihHXhX4M9wA8U2Q2Ld45AQOaRaBRZPf+ga7m/gwFB0t9RajjmcMaR8pzDB2TAt605Vj2S8k=" Feb 09 04:54:29 volumio go-librespot[27780]: time="2026-02-09T04:54:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:29 volumio go-librespot[27780]: time="2026-02-09T04:54:29+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:29 volumio go-librespot[27780]: time="2026-02-09T04:54:29+07:00" level=debug msg="completed challenge" Feb 09 04:54:29 volumio go-librespot[27780]: time="2026-02-09T04:54:29+07: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 09 04:54:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:29 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:29 volumio volumio[27447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:32 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:32 volumio volumio[27447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 09 04:54:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:32 volumio go-librespot[27788]: go-librespot daemon starting... Feb 09 04:54:32 volumio go-librespot[27789]: time="2026-02-09T04:54:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:32 volumio go-librespot[27789]: time="2026-02-09T04:54:32+07:00" level=debug msg="app state loaded" Feb 09 04:54:32 volumio go-librespot[27789]: time="2026-02-09T04:54:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:54:32 volumio volumio[27447]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=info msg="zeroconf server listening on port 35975" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="obtained new client token: AACdtsTAnein1WPHYqUxKXp+Vt8MN2BvEFi3agO6kOSpQHLtLVh0XIJpG/zyLx0V7RSy6Zh8g6LIyB5PTGS6GuHJCQMDvf1+oNa/bezJuikiyTCToNfx7yms+8M1+APifR9C8OtAdbOqORA320PR7M4XCEhZ2+QMb+pNaBiX0dRjTw71NHHFI955HDUUoyAmQMNaANWWy/gF1g1c1tZo/ztUP8UfVAfwXyqujImRNAMv2OslrN6Ql1CBaQ==" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07:00" level=debug msg="completed challenge" Feb 09 04:54:33 volumio go-librespot[27789]: time="2026-02-09T04:54:33+07: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 09 04:54:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:34 volumio volumio[27447]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:54:34 volumio volumio[27447]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:54:34 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:34 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:34 volumio volumio[27447]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:54:34 volumio volumio[27447]: info: MyVolumio login type: Token Feb 09 04:54:34 volumio volumio[27447]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:54:34 volumio volumio[27447]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:54:36 volumio volumio[27447]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:54:36 volumio volumio[27447]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:54:36 volumio volumio[27447]: info: Streaming services startup Feb 09 04:54:36 volumio volumio[27447]: info: Starting Streaming Daemon Feb 09 04:54:36 volumio sudo[27811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:54:36 volumio sudo[27811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:36 volumio volumio[27447]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:54:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 09 04:54:36 volumio sudo[27811]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:36 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:36 volumio volumio[27447]: error: Cannot start Volumio Streaming Daemon Feb 09 04:54:36 volumio volumio[27447]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:54:36 volumio volumio[27447]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:54:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:36 volumio go-librespot[27817]: go-librespot daemon starting... Feb 09 04:54:36 volumio volumio[27447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:36 volumio go-librespot[27819]: time="2026-02-09T04:54:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:36 volumio go-librespot[27819]: time="2026-02-09T04:54:36+07:00" level=debug msg="app state loaded" Feb 09 04:54:36 volumio go-librespot[27819]: time="2026-02-09T04:54:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=info msg="zeroconf server listening on port 34813" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="obtained new client token: AADbQvQZA9QgTdc1JaYmjtU/hSyEoPS2HS4PaCprDA7sBaJUqWWTb7rIQpJq/06bm8RhAcD9UzFyNpphKc+Uc4m+ZIPTfJFz1L0UDdixEWmUb2iZ5fV3qvBol8zI1nexd27zzlU1nlu8ecRL9J83kjgcXKYI7f048Wsnb1c5qfxUfQzDKZgfXvyjXIC5UZGnkfhYPXGgIDkW/7r7Xa7daVA/IXhhj7b6aSYVpDc69E3qNtZ5wiM+x/XU2Q==" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07:00" level=debug msg="completed challenge" Feb 09 04:54:37 volumio go-librespot[27819]: time="2026-02-09T04:54:37+07: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 09 04:54:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:38 volumio volumio[27447]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 09 04:54:39 volumio volumio[27447]: info: MyVolumio token set successfully Feb 09 04:54:39 volumio volumio[27447]: info: MYVOLUMIO: Adding device Feb 09 04:54:39 volumio volumio[27447]: info: MYVOLUMIO: Evaluating Server Feb 09 04:54:39 volumio volumio[27447]: info: MyVolumio status changed Feb 09 04:54:39 volumio volumio[27447]: info: Streaming services startup Feb 09 04:54:39 volumio volumio[27447]: info: Starting Streaming Daemon Feb 09 04:54:39 volumio volumio[27447]: info: Removing browser output: myVolumio user plan is not superstar Feb 09 04:54:39 volumio volumio[27447]: info: Removing audio output: Feb 09 04:54:39 volumio volumio[27447]: info: Stoppping Tunnel 1 Feb 09 04:54:39 volumio sudo[27848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:54:39 volumio sudo[27848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:39 volumio sudo[27848]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:40 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:40 volumio sudo[27851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 09 04:54:40 volumio sudo[27851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:40 volumio volumio[27447]: error: Cannot start Volumio Streaming Daemon Feb 09 04:54:40 volumio volumio[27447]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:54:40 volumio volumio[27447]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:54:40 volumio volumio[27447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:40 volumio volumio[27447]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:54:40 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:40 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:40 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 09 04:54:40 volumio sudo[27851]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:40 volumio volumio[27447]: info: Remote SSH Stopped Feb 09 04:54:40 volumio volumio[27447]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:54:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 09 04:54:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:41 volumio volumio[27447]: info: Updating MyVolumio device info Feb 09 04:54:41 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:41 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:41 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:41 volumio go-librespot[27853]: go-librespot daemon starting... Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=debug msg="app state loaded" Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:41 volumio volumio[27447]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=info msg="zeroconf server listening on port 46155" Feb 09 04:54:41 volumio go-librespot[27854]: time="2026-02-09T04:54:41+07:00" level=debug msg="obtained new client token: AADvwGPZzessekzL5JUSVz9CdbnfdL8Uak24GjAXO+o4FZBEHztFjHs29n4/ZxSTTyP+jwO2X72nAqio/ggjC14xGEyEH/CukFlbgiCqUifnWO9fZEs2Nxm9CSK1Q7+b5ipCihRVXE+5fY+loqgJjQSu9XpnUunaLuDBwdNteGOWyQ1+mr3axGEE8Ymm41xNf6CRo0K0E+YKvq1F5bg/TNStQK2pke/jcsWr3XeDYS1d4CA6LlhXw5ZSng==" Feb 09 04:54:42 volumio go-librespot[27854]: time="2026-02-09T04:54:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:42 volumio go-librespot[27854]: time="2026-02-09T04:54:42+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:42 volumio go-librespot[27854]: time="2026-02-09T04:54:42+07:00" level=debug msg="completed challenge" Feb 09 04:54:42 volumio go-librespot[27854]: time="2026-02-09T04:54:42+07: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 09 04:54:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:43 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:43 volumio volumio[27447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:44 volumio volumio[27447]: info: MYVOLUMIO: Adding device Feb 09 04:54:44 volumio volumio[27447]: info: MYVOLUMIO: Evaluating Server Feb 09 04:54:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 09 04:54:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:45 volumio go-librespot[27894]: go-librespot daemon starting... Feb 09 04:54:45 volumio volumio[27447]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:54:45 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:45 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:45 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=debug msg="app state loaded" Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:45 volumio volumio[27447]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:45 volumio go-librespot[27895]: time="2026-02-09T04:54:45+07:00" level=info msg="zeroconf server listening on port 34669" Feb 09 04:54:46 volumio volumio[27447]: info: Initializing connection to go-librespot Websocket Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07:00" level=debug msg="new websocket client" Feb 09 04:54:46 volumio volumio[27447]: info: Connection to go-librespot Websocket established Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07:00" level=debug msg="obtained new client token: AAAAiM8FWkqMaKxWeGo2/hLj6zcT2ht9r8f1DHuEG6SkjiyLIB6aJhA3r4hHBkITryzcKoiIlWU749o3vEreehO7b9kUzMQbtnAAKUUG3HBd81j6C9NhjcnDRd0axmw4vVTcEN+/utCeeOKisAjEkYKIO+RsKjSpET5K6iAjPFi5aTxcmmL8it9bImIoHEfnyeKgWZpGdlxUTSd0fdOuxVHXKikKyQMFJbG5HeAQodtljRG+P+IVKlM=" Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 04:54:46 volumio volumio[27447]: info: Updating MyVolumio device info Feb 09 04:54:46 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:46 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:46 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07:00" level=debug msg="completed challenge" Feb 09 04:54:46 volumio go-librespot[27895]: time="2026-02-09T04:54:46+07: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 09 04:54:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:46 volumio volumio[27447]: info: Connection to go-librespot Websocket closed Feb 09 04:54:47 volumio volumio[27447]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:54:47 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:54:47 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:54:47 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 09 04:54:48 volumio volumio-remote-updater[643]: Test mode disabled Feb 09 04:54:48 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 09 04:54:48 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 09 04:54:48 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 09 04:54:48 volumio volumio[27447]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 09 04:54:48 volumio volumio[27447]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 09 04:54:49 volumio volumio[27447]: info: Getting Spotify volume Feb 09 04:54:49 volumio volumio[27447]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:54:49 volumio volumio[27447]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:54:49 volumio volumio[27447]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 04:54:49 volumio volumio[27447]: errno: -111, Feb 09 04:54:49 volumio volumio[27447]: code: 'ECONNREFUSED', Feb 09 04:54:49 volumio volumio[27447]: syscall: 'connect', Feb 09 04:54:49 volumio volumio[27447]: address: '127.0.0.1', Feb 09 04:54:49 volumio volumio[27447]: port: 9879, Feb 09 04:54:49 volumio volumio[27447]: response: undefined Feb 09 04:54:49 volumio volumio[27447]: } Feb 09 04:54:49 volumio volumio[27447]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:54:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 09 04:54:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:49 volumio go-librespot[27918]: go-librespot daemon starting... Feb 09 04:54:49 volumio go-librespot[27919]: time="2026-02-09T04:54:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:49 volumio go-librespot[27919]: time="2026-02-09T04:54:49+07:00" level=debug msg="app state loaded" Feb 09 04:54:49 volumio go-librespot[27919]: time="2026-02-09T04:54:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=info msg="zeroconf server listening on port 36553" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="obtained new client token: AABCNQEAYdc+VSeQajE6stqDzr6A3ef4cVDUUQywWr/xHrBXawoxvbdsQil/Fe0wMoe/ZiTTfedoHh2dYwqYSGLML7gMuAmoD3GCe8WWyQzaS1tna+iWNloVWeixWGoy05dxqxmB0Q40EILkJFyaRUb4InGZ5zQzgB7v1BOBceqXaE8yvQzTqRLEk89Or/db2oYJdCYs/yhDvRDXnTulZFxR5aEztXMhWTFLx3O/vEf8vtGA56N5d/ozbg==" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 04:54:50 volumio sudo[27928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:53' Feb 09 04:54:50 volumio sudo[27928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07:00" level=debug msg="completed challenge" Feb 09 04:54:50 volumio go-librespot[27919]: time="2026-02-09T04:54:50+07: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 09 04:54:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:51 volumio sudo[27928]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:51 volumio volumio-remote-updater[643]: [2026-02-09 04:54:51] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 04:54:51 volumio volumio-remote-updater[643]: [2026-02-09 04:54:51] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 04:54:51 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:51 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 04:54:51 volumio systemd[1]: volumio.service: Consumed 58.516s CPU time. Feb 09 04:54:51 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:54:51 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8224. Feb 09 04:54:51 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 04:54:51 volumio systemd[1]: volumio.service: Consumed 58.516s CPU time. Feb 09 04:54:51 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 04:54:51 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:54:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 09 04:54:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:53 volumio go-librespot[27949]: go-librespot daemon starting... Feb 09 04:54:53 volumio go-librespot[27950]: time="2026-02-09T04:54:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:53 volumio go-librespot[27950]: time="2026-02-09T04:54:53+07:00" level=debug msg="app state loaded" Feb 09 04:54:53 volumio go-librespot[27950]: time="2026-02-09T04:54:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=info msg="zeroconf server listening on port 35491" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="obtained new client token: AAAlhmm96cN0OXdQtNfHF+lmrod0XR8blBKevi/41WnBKkd1ynNFNhYMKawy3h/y3gUxVL+DbLbiG3bh+1gPHJb74ydCD3BwCQWpdrM/iAWJgtIkwL+m/6W0MaccJeLyxCKmSZ9X29Y9GlvUQK/7Zn8weBiZeqmQzJQ6tv0hr2m7cu+BeI/SRk5/fe+yL5vHDvdZgacXpDEog0M9p013Ns3ULT6zTa+dQb865dWKwNxa8xslHooDfIbKzw==" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07:00" level=debug msg="completed challenge" Feb 09 04:54:54 volumio go-librespot[27950]: time="2026-02-09T04:54:54+07: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 09 04:54:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:54 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:54:54 volumio volumio[27938]: info: ----- Volumio3 ---- Feb 09 04:54:54 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:54:54 volumio volumio[27938]: info: ----- System startup ---- Feb 09 04:54:54 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:54:56 volumio volumio-remote-updater[643]: [2026-02-09 04:54:56] [connect] Successful connection Feb 09 04:54:56 volumio volumio[27938]: info: MYVOLUMIO Environment detected Feb 09 04:54:56 volumio volumio[27938]: info: Plugin folders cleanup Feb 09 04:54:56 volumio volumio[27938]: info: Scanning into folder /volumio/app/plugins/ Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category audio_interface Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category miscellanea Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category music_service Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category plugins.json Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category system_controller Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category user_interface Feb 09 04:54:56 volumio volumio[27938]: info: Scanning into folder /data/plugins/ Feb 09 04:54:56 volumio volumio[27938]: info: Scanning category music_service Feb 09 04:54:56 volumio volumio[27938]: info: Plugin folders cleanup completed Feb 09 04:54:56 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:54:56 volumio volumio[27938]: info: ----- Core plugins startup ---- Feb 09 04:54:56 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:54:56 volumio volumio[27938]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 04:54:56 volumio volumio[27938]: info: Adding plugin upnp to MyMusic Plugins Feb 09 04:54:56 volumio volumio[27938]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 04:54:56 volumio volumio[27938]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 04:54:56 volumio volumio[27938]: info: Loading plugins from folder /data/plugins/ Feb 09 04:54:56 volumio volumio[27938]: info: Loading plugin "system"... Feb 09 04:54:56 volumio volumio[27938]: info: Loading plugin "appearance"... Feb 09 04:54:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 09 04:54:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:54:58 volumio go-librespot[27970]: go-librespot daemon starting... Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=debug msg="app state loaded" Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "network"... Feb 09 04:54:58 volumio volumio[27938]: info: Refreshing Cached IP Addresses Feb 09 04:54:58 volumio sudo[27979]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:54:58 volumio sudo[27979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:58 volumio sudo[27981]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "services"... Feb 09 04:54:58 volumio sudo[27981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "alsa_controller"... Feb 09 04:54:58 volumio sudo[27979]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:58 volumio sudo[27981]: pam_unix(sudo:session): session closed for user root Feb 09 04:54:58 volumio sudo[27989]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=info msg="zeroconf server listening on port 39661" Feb 09 04:54:58 volumio sudo[27989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:54:58 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "wizard"... Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "networkfs"... Feb 09 04:54:58 volumio volumio[27938]: info: Starting Udev Watcher for removable devices Feb 09 04:54:58 volumio go-librespot[27971]: time="2026-02-09T04:54:58+07:00" level=debug msg="obtained new client token: AADSzkKZl9HA8EKYJ5NAzwdjrXbFmQ0tdvao2gYBhEsImyPqLxPbCj9i16s/Z8We++UvDJfBvNXG75CPEm7nttZ/yG8TFhZK2YDftrCvXpxk23bKQrUmUl4Vy6by/l1L5dNrNmZ+ivNluFLUvF6AjY42hrCIM2RN5YBd5RUR4i/8YLrVaAi1yjQFzqA0PPekEM5/nH+FUcFmMIa+Hl58GFelk3aR1Xja3S300tPcMDAsAqsBq4t88ofh9g==" Feb 09 04:54:58 volumio volumio[27938]: info: Ignoring mount for partition: boot Feb 09 04:54:58 volumio volumio[27938]: info: Ignoring mount for partition: volumio Feb 09 04:54:58 volumio volumio[27938]: info: Ignoring mount for partition: volumio_data Feb 09 04:54:58 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "volumio_command_line_client"... Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "upnp"... Feb 09 04:54:58 volumio volumio[27938]: info: [1770587698972] Starting Upmpd Daemon Feb 09 04:54:58 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "my_music"... Feb 09 04:54:58 volumio volumio[27938]: info: Loading plugin "mpd"... Feb 09 04:54:59 volumio go-librespot[27971]: time="2026-02-09T04:54:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:54:59 volumio go-librespot[27971]: time="2026-02-09T04:54:59+07:00" level=debug msg="completed keyexchange" Feb 09 04:54:59 volumio go-librespot[27971]: time="2026-02-09T04:54:59+07:00" level=debug msg="completed challenge" Feb 09 04:54:59 volumio go-librespot[27971]: time="2026-02-09T04:54:59+07: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 09 04:54:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:54:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:54:59 volumio volumio[27938]: info: Loading plugin "upnp_browser"... Feb 09 04:55:01 volumio sudo[27989]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 09 04:55:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:02 volumio go-librespot[28014]: go-librespot daemon starting... Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=debug msg="app state loaded" Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:02 volumio volumio[27938]: info: Starting UPNP Browser Feb 09 04:55:02 volumio volumio[27938]: info: Loading plugin "alarm-clock"... Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:55:02 volumio volumio[27938]: info: Loading plugin "airplay_emulation"... Feb 09 04:55:02 volumio go-librespot[28015]: time="2026-02-09T04:55:02+07:00" level=info msg="zeroconf server listening on port 45181" Feb 09 04:55:02 volumio volumio[27938]: info: Starting Shairport Sync Feb 09 04:55:02 volumio volumio[27938]: info: Loading plugin "last_100"... Feb 09 04:55:03 volumio volumio[27938]: info: Loading plugin "webradio"... Feb 09 04:55:03 volumio go-librespot[28015]: time="2026-02-09T04:55:03+07:00" level=debug msg="obtained new client token: AAAGDioQHKUzfXZXmyghWa9gUB3IfJJYSwQucMnb9tyIkjNI8sN5i4q0kNZ9EALsCef0/HX3r5zz5PzFp80R02oTVV21PXnZPIqJdq8hQFnMOqVauyaus6om1eJuXM0/u3/R+NuawKFdy15f5UKfL1NJSkZww8h31+mTOK3K1aGkjlXmQv/mS6FuJy4CJf2WdgK6Xzv4BBIsaOiyXgKucg5zl7okHSUQtpn31bpcqvk7hEWVbmFPrKE=" Feb 09 04:55:03 volumio volumio[27938]: info: Loading plugin "i2s_dacs"... Feb 09 04:55:03 volumio volumio[27938]: info: Loading plugin "volumiodiscovery"... Feb 09 04:55:03 volumio go-librespot[28015]: time="2026-02-09T04:55:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:03 volumio volumio[27938]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:55:03 volumio volumio[27938]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:55:03 volumio volumio[27938]: *** WARNING *** For more information see Feb 09 04:55:03 volumio volumio[27938]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:55:03 volumio node[27938]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:55:03 volumio volumio[27938]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:55:03 volumio volumio[27938]: *** WARNING *** For more information see Feb 09 04:55:03 volumio node[27938]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:55:03 volumio node[27938]: *** WARNING *** For more information see Feb 09 04:55:03 volumio node[27938]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:55:03 volumio node[27938]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:55:03 volumio node[27938]: *** WARNING *** For more information see Feb 09 04:55:03 volumio volumio[27938]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 04:55:03 volumio volumio[27938]: info: Discovery: Started advertising with name: Volumio Feb 09 04:55:03 volumio go-librespot[28015]: time="2026-02-09T04:55:03+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:03 volumio go-librespot[28015]: time="2026-02-09T04:55:03+07:00" level=debug msg="completed challenge" Feb 09 04:55:03 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:55:03 volumio volumio[27938]: info: Loading plugin "spop"... Feb 09 04:55:03 volumio go-librespot[28015]: time="2026-02-09T04:55:03+07: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 09 04:55:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:05 volumio volumio[27938]: info: Loading plugin "ytcr"... Feb 09 04:55:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 09 04:55:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:06 volumio go-librespot[28024]: go-librespot daemon starting... Feb 09 04:55:06 volumio go-librespot[28025]: time="2026-02-09T04:55:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:06 volumio go-librespot[28025]: time="2026-02-09T04:55:06+07:00" level=debug msg="app state loaded" Feb 09 04:55:06 volumio go-librespot[28025]: time="2026-02-09T04:55:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=info msg="zeroconf server listening on port 45609" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="obtained new client token: AADO6Pd1NGdvDo0p9nxFH2YmMgvMDIg1mLCwt/zY9hkrsAf+4LDqIGUpcQokpU1NpbddmLiU72QYL/vCSK1IaYxFgGmYgSbPFvLqXEBUm4n/O1gDYwDcaqckDRWpCm57g391uUo7DpyCc9farmucGMmiX5ydCvvsyfJAxSYSyjYKMETy/3UDPNBbx1PkP/fGJsls2sEifqozrHt+9SoCcZrExDOGsE4zVbY0XIcV9wIXzi895/d5J0d48A==" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07:00" level=debug msg="completed challenge" Feb 09 04:55:07 volumio go-librespot[28025]: time="2026-02-09T04:55:07+07: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 09 04:55:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:07 volumio volumio[27938]: info: Loading plugin "ytmusic"... Feb 09 04:55:08 volumio volumio-remote-updater[643]: [2026-02-09 04:55:08] [connect] Successful connection Feb 09 04:55:08 volumio volumio[27938]: info: Loading plugin "outputs"... Feb 09 04:55:08 volumio volumio[27938]: info: Loading plugin "albumart"... Feb 09 04:55:08 volumio volumio[27938]: info: Plugin example_plugin is not enabled Feb 09 04:55:08 volumio volumio[27938]: info: Loading plugin "inputs"... Feb 09 04:55:08 volumio volumio[27938]: info: Loading plugin "updater_comm"... Feb 09 04:55:09 volumio volumio[27938]: info: Plugin mpdemulation is not enabled Feb 09 04:55:09 volumio volumio[27938]: info: Loading plugin "rest_api"... Feb 09 04:55:09 volumio volumio[27938]: info: Loading plugin "websocket"... Feb 09 04:55:09 volumio volumio[27938]: info: Starting Socket.io Server version 1.7.4 Feb 09 04:55:09 volumio volumio[27938]: info: Loading plugin "RoonBridge"... Feb 09 04:55:09 volumio volumio[27938]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 04:55:09 volumio volumio[27938]: info: Loading i18n strings for locale en Feb 09 04:55:09 volumio volumio[27938]: Updating browse sources language Feb 09 04:55:09 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:55:10 volumio volumio[28046]: Forking 3 albumart workers Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::initPlayerControls Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: Express server listening on port 3000 Feb 09 04:55:10 volumio volumio[27938]: [Metrics] WebUI: 16s 158.35ms Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::resetVolumioState Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::getcurrentVolume Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:55:10 volumio sudo[28092]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:55:10 volumio sudo[28089]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:55:10 volumio sudo[28092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:10 volumio sudo[28089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:10 volumio sudo[28092]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:10 volumio sudo[28089]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:10 volumio volumio[27938]: info: Volumio Network Manager: Network status updated: 1 Feb 09 04:55:10 volumio volumio-remote-updater[643]: [2026-02-09 04:55:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770587708 101 Feb 09 04:55:10 volumio volumio[27938]: 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 09 04:55:10 volumio volumio[27938]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::pushState Feb 09 04:55:10 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::volumioPushState Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::updateTrackBlock Feb 09 04:55:10 volumio volumio[27938]: info: CorePlayQueue::getTrackBlock Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:55:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 09 04:55:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:10 volumio go-librespot[28099]: go-librespot daemon starting... Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:10 volumio volumio[27938]: info: Reloading queue from file Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::setRepeat null single undefined Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::pushState Feb 09 04:55:10 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::volumioPushState Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::setRandom null Feb 09 04:55:10 volumio volumio[27938]: info: CoreStateMachine::pushState Feb 09 04:55:10 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:10 volumio volumio[27938]: info: CoreCommandRouter::volumioPushState Feb 09 04:55:10 volumio volumio[27938]: info: Setting Device type: Raspberry PI Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=debug msg="app state loaded" Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:11 volumio volumio[27938]: info: Completed loading Core Plugins Feb 09 04:55:11 volumio volumio[27938]: info: Preparing to generate the ALSA configuration file Feb 09 04:55:11 volumio volumio[27938]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:55:11 volumio volumio[27938]: info: CoreStateMachine::pushState Feb 09 04:55:11 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::volumioPushState Feb 09 04:55:11 volumio volumio[27938]: info: Asound.conf file unchanged, so no further update is needed Feb 09 04:55:11 volumio volumio[27938]: info: Output device has changed, restarting MPD Feb 09 04:55:11 volumio sudo[28115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 04:55:11 volumio sudo[28115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:11 volumio volumio[27938]: info: Output device has changed, restarting Shairport Sync Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:11 volumio sudo[28120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:55:11 volumio sudo[28120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:11 volumio sudo[28117]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:55:11 volumio sudo[28117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:11 volumio sudo[28117]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:11 volumio volumio[27938]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:55:11 volumio volumio[27938]: info: ___________ START PLUGINS ___________ Feb 09 04:55:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 04:55:11 volumio sudo[28115]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:11 volumio volumio[27938]: info: ControllerMpd::onStart: Initializing MPD Feb 09 04:55:11 volumio volumio[27938]: info: Creating MPD Configuration file Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:55:11 volumio volumio[27938]: info: [1770587711722] CoreMusicLibrary::Adding element Media Servers Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:55:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:55:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:55:11 volumio systemd[1]: mpd.service: Consumed 7.028s CPU time. Feb 09 04:55:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:55:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:55:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=info msg="zeroconf server listening on port 45235" Feb 09 04:55:11 volumio sudo[28129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:55:11 volumio sudo[28129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:11 volumio sudo[28129]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:11 volumio volumio[27938]: info: UPNP Browser: Client initialized successfully Feb 09 04:55:11 volumio sudo[28131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:55:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:55:11 volumio sudo[28131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:11 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:55:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:55:11 volumio go-librespot[28103]: time="2026-02-09T04:55:11+07:00" level=debug msg="obtained new client token: AADm21SxzObQTtM2qE9y5ShS9+dUdEocsewGkl0HOvbtOKYCOo+oFU+rsf8Xb2stbXU2592QSky/JE9PyRZjUV6qpcA25rJDZqZV1j3TFI82IEBKW7TXEc5jLqBTLPcgP//fxHm4wgTtHP/ZooBqkuyfgM2kZPU4+moRvdkjWeofA79ckNmWrnorzsDRzYKa/wbZfcOAnm/u0MvuXvIzemsDYF7TSAPjppl8SlpUxoF9ANtPZ/PKQJk8Iw==" Feb 09 04:55:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:55:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:55:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:55:12 volumio volumio[27938]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:12 volumio volumio[27938]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:55:12 volumio volumio[27938]: info: [1770587712103] CoreMusicLibrary::Adding element Last_100 Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:55:12 volumio go-librespot[28103]: time="2026-02-09T04:55:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:55:12 volumio volumio[27938]: info: [1770587712122] CoreMusicLibrary::Adding element Webradio Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:55:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:55:12 volumio volumio[27938]: info: Initializing BBC Radios Feb 09 04:55:12 volumio go-librespot[28103]: time="2026-02-09T04:55:12+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:12 volumio go-librespot[28103]: time="2026-02-09T04:55:12+07:00" level=debug msg="completed challenge" Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:12 volumio volumio[27938]: info: Creating Spotify config file Feb 09 04:55:12 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:12 volumio go-librespot[28103]: time="2026-02-09T04:55:12+07: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 09 04:55:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:12 volumio sudo[28145]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 04:55:12 volumio sudo[28145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 04:55:12 volumio sudo[28145]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:13 volumio volumio[27938]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:55:13 volumio volumio[27938]: info: [1770587713483] CoreMusicLibrary::Adding element YouTube Music Feb 09 04:55:13 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:55:13 volumio volumio[27938]: Cannot find translation for source YouTube Music Feb 09 04:55:13 volumio volumio[27938]: info: Volumio Calling Home Feb 09 04:55:13 volumio volumio[28056]: Starting albumart workers Feb 09 04:55:13 volumio sudo[28162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 04:55:13 volumio sudo[28162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:13 volumio volumio[28058]: Starting albumart workers Feb 09 04:55:13 volumio sudo[28162]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:13 volumio volumio[28057]: Starting albumart workers Feb 09 04:55:14 volumio volumio[27938]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:55:14 volumio volumio[27938]: info: Discovery: Found device Volumio Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::volumioGetState Feb 09 04:55:14 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:14 volumio volumio[27938]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:55:14 volumio volumio[27938]: info: Discovery: Found device Volumio Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::volumioGetState Feb 09 04:55:14 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:14 volumio volumio[27938]: info: MPD Permissions set Feb 09 04:55:14 volumio volumio[27938]: info: MPD Permissions set Feb 09 04:55:14 volumio volumio[27938]: info: Upmpdcli Daemon Started Feb 09 04:55:14 volumio volumio[27938]: info: Spotify config file written Feb 09 04:55:14 volumio sudo[28168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 04:55:14 volumio sudo[28168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:14 volumio volumio[27938]: 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 09 04:55:14 volumio volumio[27938]: info: Volumio called home Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio go-librespot[28175]: go-librespot daemon starting... Feb 09 04:55:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:14 volumio sudo[28168]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:14 volumio go-librespot[28178]: time="2026-02-09T04:55:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:14 volumio go-librespot[28178]: time="2026-02-09T04:55:14+07:00" level=debug msg="app state loaded" Feb 09 04:55:14 volumio go-librespot[28178]: time="2026-02-09T04:55:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:55:14 volumio volumio[27938]: info: No need to fix Spotify hosts Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=info msg="zeroconf server listening on port 35301" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="obtained new client token: AADNgvj70CODlb7rgnSpyyXzxAJvW3F8fbLtDkh9a+lecq/kiksycIu1SQy/SKCgadgTgoT4xlyHKmvccbN9JG75zUwkqh2l3r8prd4TN3mgouu21xFvCIpU3KDOMzc8CeMFuOE/LTB/e+IrxTRki9UMY5gO22Nei16UKDSfsaq4agBOpx0Ep3bIWYTR+mHUvK6+KCRYJbm1vgzmo3h2LHUPTdrLQ27YHDvSa84cTgBiRNBjAe5zReRXGg==" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:15 volumio go-librespot[28178]: time="2026-02-09T04:55:15+07:00" level=debug msg="completed challenge" Feb 09 04:55:16 volumio go-librespot[28178]: time="2026-02-09T04:55:16+07: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 09 04:55:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:16 volumio volumio[27938]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:55:16 volumio volumio[27938]: SPOTIFY: BQDFe5b8h14km5NZXBbdc7WtKPCEachthRGAa_S-c6dGTWmWwm6iIS_iMFO1-puKQLX8bHn7rXMwDsuz0BWcLX8m9ADo20KrmhS5DtDz7ewh7CveMBjDIdzxYuE16nTtESo6vFGBYO2p6rEVnQDY12n3JtiTNysbWAKCqZgOW6mCMrwXUaFuMoAP-z9Ln9WudZ_RSqMDexYZ8RwsGB6RVG5W8ltQqOIG5AjPirzTNt9AHJ_3WqrjvxwP9cYsX8kPXkiPP8MjIrzzdchY_28vquMz5gDGosQeyuzwnMpM8Ms5kt0zPjTezp-5 Feb 09 04:55:16 volumio volumio[27938]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:55:16 volumio volumio[27938]: info: New Spotify access token = BQDFe5b8h14km5NZXBbdc7WtKPCEachthRGAa_S-c6dGTWmWwm6iIS_iMFO1-puKQLX8bHn7rXMwDsuz0BWcLX8m9ADo20KrmhS5DtDz7ewh7CveMBjDIdzxYuE16nTtESo6vFGBYO2p6rEVnQDY12n3JtiTNysbWAKCqZgOW6mCMrwXUaFuMoAP-z9Ln9WudZ_RSqMDexYZ8RwsGB6RVG5W8ltQqOIG5AjPirzTNt9AHJ_3WqrjvxwP9cYsX8kPXkiPP8MjIrzzdchY_28vquMz5gDGosQeyuzwnMpM8Ms5kt0zPjTezp-5 Feb 09 04:55:16 volumio volumio[27938]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 04:55:16 volumio volumio[27938]: info: Starting Shairport Sync Feb 09 04:55:16 volumio volumio[27938]: info: Starting Shairport Sync Feb 09 04:55:16 volumio volumio[27938]: info: Starting Shairport Sync Feb 09 04:55:16 volumio sudo[28208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:55:16 volumio sudo[28208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:16 volumio sudo[28210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:55:16 volumio sudo[28210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:16 volumio sudo[28212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:55:16 volumio sudo[28212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:55:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:55:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:55:16 volumio systemd[1]: shairport-sync.service: Consumed 2.353s CPU time. Feb 09 04:55:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:55:16 volumio sudo[28208]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:16 volumio sudo[28210]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:16 volumio sudo[28212]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:16 volumio volumio[27938]: info: CoreCommandRouter::volumioGetState Feb 09 04:55:16 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:17 volumio volumio[27938]: info: Shairport-Sync Started Feb 09 04:55:17 volumio volumio[27938]: Error adding Membership: Error: addMembership EINVAL Feb 09 04:55:17 volumio volumio[27938]: info: Shairport-Sync Started Feb 09 04:55:17 volumio volumio[27938]: info: Shairport-Sync Started Feb 09 04:55:17 volumio volumio[27938]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 09 04:55:17 volumio volumio[27938]: info: Spotify Successfully logged in Feb 09 04:55:17 volumio volumio[27938]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:55:17 volumio volumio[27938]: info: [1770587717159] CoreMusicLibrary::Adding element Spotify Feb 09 04:55:17 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:55:17 volumio volumio[27938]: Cannot find translation for source YouTube Music Feb 09 04:55:17 volumio volumio[27938]: Cannot find translation for source Spotify Feb 09 04:55:17 volumio volumio[27938]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 04:55:17 volumio volumio[27938]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:55:17 volumio volumio[27938]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:55:17 volumio volumio[27938]: info: CoreCommandRouter::volumioGetState Feb 09 04:55:17 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:17 volumio volumio[27938]: info: CoreStateMachine::pushState Feb 09 04:55:17 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:17 volumio volumio[27938]: info: CoreCommandRouter::volumioPushState Feb 09 04:55:19 volumio volumio[27938]: info: go-librespot daemon successfully initialized Feb 09 04:55:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 09 04:55:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:19 volumio go-librespot[28248]: go-librespot daemon starting... Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=debug msg="app state loaded" Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:19 volumio mpd[28160]: 2026-02-09T04:55:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 04:55:19 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 04:55:19 volumio sudo[28120]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:19 volumio sudo[28131]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:19 volumio volumio[27938]: error: MPD error: The expression evaluated to a falsy value: Feb 09 04:55:19 volumio volumio[27938]: assert.ok(self.idling) Feb 09 04:55:19 volumio volumio[27938]: error: The expression evaluated to a falsy value: Feb 09 04:55:19 volumio volumio[27938]: assert.ok(self.idling) Feb 09 04:55:19 volumio volumio[27938]: info: MPD running with PID28160 Feb 09 04:55:19 volumio volumio[27938]: ,establishing connection Feb 09 04:55:19 volumio volumio[27938]: error: updateQueue error: null Feb 09 04:55:19 volumio volumio[27938]: info: Completed starting Core Plugins Feb 09 04:55:19 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:55:19 volumio volumio[27938]: info: ----- MyVolumio plugins startup ---- Feb 09 04:55:19 volumio volumio[27938]: info: ------------------------------------------- Feb 09 04:55:19 volumio volumio[27938]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 04:55:19 volumio volumio[27938]: error: updateQueue error: null Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:55:19 volumio go-librespot[28249]: time="2026-02-09T04:55:19+07:00" level=info msg="zeroconf server listening on port 41871" Feb 09 04:55:20 volumio go-librespot[28249]: time="2026-02-09T04:55:20+07:00" level=debug msg="obtained new client token: AAAo68j+rVnIk2jhDMyd0VQ7k+yumX8rg7pTWzrir4W6ScDqHUf8uBBoOM3bNqueZmByb4caZXNfhVsS1zUtdxq4iV19oxqE+4D0paNjfRVdPS2onco2aurROv0lsDNQK83ZIb98EL6zcVTg1ftzRSuVGRbJ4+oAdIUiXWdGwdsWv1JiAMUPs6/sxW4qltBUOGWPiMDvvZhIXupUz2Rx8vz8BSvZl0bspKUc76UyFqS93A3zlYHa+54=" Feb 09 04:55:20 volumio go-librespot[28249]: time="2026-02-09T04:55:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:20 volumio go-librespot[28249]: time="2026-02-09T04:55:20+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:20 volumio go-librespot[28249]: time="2026-02-09T04:55:20+07:00" level=debug msg="completed challenge" Feb 09 04:55:20 volumio go-librespot[28249]: time="2026-02-09T04:55:20+07: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 09 04:55:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:22 volumio volumio[27938]: info: Initializing connection to go-librespot Websocket Feb 09 04:55:22 volumio volumio[27938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:55:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 09 04:55:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:23 volumio go-librespot[28260]: go-librespot daemon starting... Feb 09 04:55:23 volumio go-librespot[28261]: time="2026-02-09T04:55:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:23 volumio go-librespot[28261]: time="2026-02-09T04:55:23+07:00" level=debug msg="app state loaded" Feb 09 04:55:23 volumio go-librespot[28261]: time="2026-02-09T04:55:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=info msg="zeroconf server listening on port 35347" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="obtained new client token: AACERYn86b6T6HpEVweLyvhof/O0056Z5x1Q3LyKDLmBFNyWfet4rUqHe/v2ByaAwuYZbsc4XeVuzkS4b7yVBknWN7iPkv6shESYZlyuXWyL9RfMczi9zexEnMGrXBrQRKiTFUCzXmPQ/sIE0xjH+PfXjJ3TibBVOEoBgHNMxjRa5SoBD8WWPNXmkD6rADskbpOmOI0Ww0NZSb6lXXKPQASsRRfIZCzHBkkS9tiNlQbU4w0cJ2kPugXbYQ==" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07:00" level=debug msg="completed challenge" Feb 09 04:55:24 volumio go-librespot[28261]: time="2026-02-09T04:55:24+07: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 09 04:55:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:24 volumio volumio[27938]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:55:24 volumio nmbd[966]: [2026/02/09 04:55:24.792449, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 09 04:55:24 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 09 04:55:24 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 09 04:55:25 volumio volumio[27938]: info: Initializing connection to go-librespot Websocket Feb 09 04:55:25 volumio volumio[27938]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:55:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 09 04:55:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:27 volumio go-librespot[28269]: go-librespot daemon starting... Feb 09 04:55:27 volumio go-librespot[28270]: time="2026-02-09T04:55:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:27 volumio go-librespot[28270]: time="2026-02-09T04:55:27+07:00" level=debug msg="app state loaded" Feb 09 04:55:27 volumio go-librespot[28270]: time="2026-02-09T04:55:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:28 volumio volumio[27938]: info: Initializing connection to go-librespot Websocket Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="new websocket client" Feb 09 04:55:28 volumio volumio[27938]: info: Connection to go-librespot Websocket established Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=info msg="zeroconf server listening on port 39007" Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="obtained new client token: AAARo/jcpu1nbBewPcaxStbPJG+7qZjgU9cUjJVZP6TURDXgGHFvcvwOlMDAtokufLKjVMHwixNe3zjusf7/G5feVeGsjMO9EpqqHmzQb6RQt6rnMslJx+T3cH7jlXCiAuxO+hmxE68kKsFBVmJv5PSvb40ymapFQLrLLheqSZJog6ngczK2VstQ7Ofn/laFrYxFKcVTOvW7qizdPOw1e6vhJxfGxGOlRpYyQIakSEy4U1jTt9xr8uel0A==" Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:55:28 volumio volumio[27938]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07:00" level=debug msg="completed challenge" Feb 09 04:55:28 volumio go-librespot[28270]: time="2026-02-09T04:55:28+07: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 09 04:55:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:30 volumio volumio[27938]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:55:30 volumio volumio[27938]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:55:30 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:30 volumio volumio[27938]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:55:30 volumio volumio[27938]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:55:30 volumio volumio[27938]: info: MyVolumio login type: Token Feb 09 04:55:30 volumio volumio[27938]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:55:30 volumio volumio[27938]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:55:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 09 04:55:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:55:32 volumio go-librespot[28292]: go-librespot daemon starting... Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=debug msg="app state loaded" Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:55:32 volumio volumio[27938]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:55:32 volumio volumio[27938]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:55:32 volumio volumio[27938]: info: Streaming services startup Feb 09 04:55:32 volumio volumio[27938]: info: Starting Streaming Daemon Feb 09 04:55:32 volumio sudo[28301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:55:32 volumio sudo[28301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:55:32 volumio volumio[27938]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:55:32 volumio sudo[28301]: pam_unix(sudo:session): session closed for user root Feb 09 04:55:32 volumio volumio[27938]: info: Getting Spotify volume Feb 09 04:55:32 volumio volumio[27938]: info: Connection to go-librespot Websocket closed Feb 09 04:55:32 volumio volumio[27938]: error: Cannot start Volumio Streaming Daemon Feb 09 04:55:32 volumio volumio[27938]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:55:32 volumio volumio[27938]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:55:32 volumio volumio[27938]: 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 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=info msg="zeroconf server listening on port 41037" Feb 09 04:55:32 volumio volumio[27938]: info: CoreCommandRouter::volumioGetState Feb 09 04:55:32 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:32 volumio volumio[27938]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 09 04:55:32 volumio volumio[27938]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 04:55:32 volumio volumio[27938]: SPOTIFY: VOLUMIO VOLUME 100 Feb 09 04:55:32 volumio volumio[27938]: info: Aligning Spotify Volume to Volumio Volume Feb 09 04:55:32 volumio volumio[27938]: info: CoreCommandRouter::volumioGetState Feb 09 04:55:32 volumio volumio[27938]: info: CorePlayQueue::getTrack 0 Feb 09 04:55:32 volumio volumio[27938]: info: Setting Spotify Volume from Volumio: 100 Feb 09 04:55:32 volumio go-librespot[28293]: time="2026-02-09T04:55:32+07:00" level=debug msg="obtained new client token: AACpBKb1YzpLOaNhsRKFvys6H69bZyZD0g8RB0cljGiYlKZ9qmVQaOkutpd2QGc+IHu0KV9m1LduJTfWyVAWNzw6sXLMwjA21wMlNTF6GMOfAGLhiG/ZHVdiyhrnUDJDxAI2IJyXpQ+IigUPbqCJ+V2FgP9UltEFWIJOrdeXX10CFfm8DBnWgB45uTSrTDoXpE6YBkHfdkg4FKqeQMzu0y9D4HR4aHH+XX8OFmOwG8l+v6oHAgT3qDHn7g==" Feb 09 04:55:33 volumio go-librespot[28293]: time="2026-02-09T04:55:33+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 09 04:55:33 volumio go-librespot[28293]: time="2026-02-09T04:55:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 04:55:33 volumio go-librespot[28293]: time="2026-02-09T04:55:33+07:00" level=debug msg="completed keyexchange" Feb 09 04:55:33 volumio go-librespot[28293]: time="2026-02-09T04:55:33+07:00" level=debug msg="completed challenge" Feb 09 04:55:33 volumio go-librespot[28293]: time="2026-02-09T04:55:33+07: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 09 04:55:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:55:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:55:33 volumio volumio[27938]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:55:33 volumio volumio[27938]: Error: socket hang up Feb 09 04:55:33 volumio volumio[27938]: at connResetException (node:internal/errors:720:14) Feb 09 04:55:33 volumio volumio[27938]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 04:55:33 volumio volumio[27938]: at Socket.emit (node:events:526:35) Feb 09 04:55:33 volumio volumio[27938]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 04:55:33 volumio volumio[27938]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 04:55:33 volumio volumio[27938]: code: 'ECONNRESET', Feb 09 04:55:33 volumio volumio[27938]: response: undefined Feb 09 04:55:33 volumio volumio[27938]: } Feb 09 04:55:33 volumio volumio[27938]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:55:34 volumio sudo[28323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:54' Feb 09 04:55:34 volumio sudo[28323]: 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"