Feb 10 13:32:00 volumio volumio[29789]: info: Starting UPNP Browser Feb 10 13:32:00 volumio volumio[29789]: info: Loading plugin "alarm-clock"... Feb 10 13:32:00 volumio volumio[29789]: info: Loading plugin "airplay_emulation"... Feb 10 13:32:00 volumio volumio[29789]: info: Starting Shairport Sync Feb 10 13:32:00 volumio volumio[29789]: info: Loading plugin "last_100"... Feb 10 13:32:00 volumio volumio[29789]: info: Loading plugin "webradio"... Feb 10 13:32:00 volumio volumio[29789]: info: Loading plugin "i2s_dacs"... Feb 10 13:32:00 volumio volumio[29789]: info: Loading plugin "volumiodiscovery"... Feb 10 13:32:00 volumio volumio[29789]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:00 volumio volumio[29789]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:00 volumio volumio[29789]: *** WARNING *** For more information see Feb 10 13:32:00 volumio volumio[29789]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:00 volumio volumio[29789]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:00 volumio volumio[29789]: *** WARNING *** For more information see Feb 10 13:32:00 volumio node[29789]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:00 volumio node[29789]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:00 volumio node[29789]: *** WARNING *** For more information see Feb 10 13:32:00 volumio node[29789]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:00 volumio node[29789]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:00 volumio node[29789]: *** WARNING *** For more information see Feb 10 13:32:00 volumio volumio[29789]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:32:00 volumio volumio[29789]: info: Discovery: Started advertising with name: Volumio Feb 10 13:32:00 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:32:01 volumio volumio[29789]: info: Loading plugin "spop"... Feb 10 13:32:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Feb 10 13:32:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:01 volumio go-librespot[29869]: go-librespot daemon starting... Feb 10 13:32:01 volumio go-librespot[29870]: time="2026-02-10T13:32:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:01 volumio go-librespot[29870]: time="2026-02-10T13:32:01+07:00" level=debug msg="app state loaded" Feb 10 13:32:01 volumio go-librespot[29870]: time="2026-02-10T13:32:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32: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 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32: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 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32: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 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32:02+07:00" level=info msg="zeroconf server listening on port 41811" Feb 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32:02+07:00" level=debug msg="obtained new client token: AACBd/6oCk4KwsFdCDhgVgJzdqsPhUcCTjNARvv9f7JxbsGb96Vb/e0VMi0NS4e8RUwDEiwQtf41vzqZTZFAkivnPXWu+EPQybnQLHRLJktkiG+7VoXHbW/4LyqEq5bT/S6BuRnO/I/eABl9gKl7YekAsUjN2Wlr1shRgX7D4H4Y0BoBZze7iuJQr9dtdT8pRb+rpM9qzdMMGAENeiFQPoOk/FdNoGLLHd9oLtIfB/TnPDZm3X82hOg9WQ==" Feb 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:02 volumio volumio[29789]: info: Loading plugin "ytcr"... Feb 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32:02+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:02 volumio go-librespot[29870]: time="2026-02-10T13:32:02+07:00" level=debug msg="completed challenge" Feb 10 13:32:03 volumio go-librespot[29870]: time="2026-02-10T13:32: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 10 13:32:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:05 volumio volumio[29789]: info: Loading plugin "ytmusic"... Feb 10 13:32:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Feb 10 13:32:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:06 volumio go-librespot[29878]: go-librespot daemon starting... Feb 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+07:00" level=debug msg="app state loaded" Feb 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:06 volumio volumio-remote-updater[643]: [2026-02-10 13:32:06] [connect] Successful connection Feb 10 13:32:06 volumio volumio[29789]: info: Loading plugin "outputs"... Feb 10 13:32:06 volumio volumio[29789]: info: Loading plugin "albumart"... Feb 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+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 10 13:32:06 volumio volumio[29789]: info: Plugin example_plugin is not enabled Feb 10 13:32:06 volumio volumio[29789]: info: Loading plugin "inputs"... Feb 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+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 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+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 10 13:32:06 volumio volumio[29789]: info: Loading plugin "updater_comm"... Feb 10 13:32:06 volumio go-librespot[29879]: time="2026-02-10T13:32:06+07:00" level=info msg="zeroconf server listening on port 35851" Feb 10 13:32:06 volumio volumio[29789]: info: Plugin mpdemulation is not enabled Feb 10 13:32:06 volumio volumio[29789]: info: Loading plugin "rest_api"... Feb 10 13:32:06 volumio volumio[29789]: info: Loading plugin "websocket"... Feb 10 13:32:06 volumio volumio[29789]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:32:06 volumio volumio[29789]: info: Loading plugin "RoonBridge"... Feb 10 13:32:07 volumio go-librespot[29879]: time="2026-02-10T13:32:07+07:00" level=debug msg="obtained new client token: AACFRIzKEkRkE52HhNUm+6BpurbHAHl8tfFBPpUoFfKTSu1mlyl0yWDTY4MzONhAp5ZCKmVctAgfSBNdoi3LYTfRQ4g423RGkM8MU8WmsoiJHUjP4fbiAxc/k9MyDu7dEbJqiF1j7cP65HBHMzTAdYgT4VAuNsdA8yFwNERWYTkk/7roju2WqP4Y5RJtajJJDBf8D6ZtW195xEU0xCxHtncx7sJr8Uk0aR/ZRtwyeo5LHxPV0xD5CdCSkg==" Feb 10 13:32:07 volumio go-librespot[29879]: time="2026-02-10T13:32:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:07 volumio go-librespot[29879]: time="2026-02-10T13:32:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:32:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:07 volumio volumio[29789]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:32:07 volumio volumio[29789]: info: Loading i18n strings for locale en Feb 10 13:32:07 volumio volumio[29789]: Updating browse sources language Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::initPlayerControls Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:32:07 volumio volumio[29901]: Forking 3 albumart workers Feb 10 13:32:07 volumio volumio[29789]: Express server listening on port 3000 Feb 10 13:32:07 volumio volumio[29789]: [Metrics] WebUI: 16s 80.73ms Feb 10 13:32:07 volumio volumio[29789]: info: CoreStateMachine::resetVolumioState Feb 10 13:32:07 volumio volumio[29789]: info: CoreStateMachine::getcurrentVolume Feb 10 13:32:07 volumio volumio[29789]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:32:08 volumio sudo[29936]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:32:08 volumio sudo[29936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:08 volumio sudo[29936]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:08 volumio sudo[29938]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:32:08 volumio sudo[29938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:08 volumio sudo[29938]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:08 volumio volumio[29789]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:32:08 volumio volumio[29789]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::pushState Feb 10 13:32:08 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::updateTrackBlock Feb 10 13:32:08 volumio volumio[29789]: info: CorePlayQueue::getTrackBlock Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:32:08 volumio volumio-remote-updater[643]: [2026-02-10 13:32:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770705126 101 Feb 10 13:32:08 volumio volumio[29789]: 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 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:08 volumio volumio[29789]: info: Reloading queue from file Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::pushState Feb 10 13:32:08 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::setRandom null Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::pushState Feb 10 13:32:08 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:08 volumio volumio[29789]: info: Setting Device type: Raspberry PI Feb 10 13:32:08 volumio volumio[29789]: info: Completed loading Core Plugins Feb 10 13:32:08 volumio volumio[29789]: info: Preparing to generate the ALSA configuration file Feb 10 13:32:08 volumio volumio[29789]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:32:08 volumio volumio[29789]: info: CoreStateMachine::pushState Feb 10 13:32:08 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:08 volumio volumio[29789]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:32:08 volumio volumio[29789]: info: Output device has changed, restarting MPD Feb 10 13:32:08 volumio volumio[29789]: info: Output device has changed, restarting Shairport Sync Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:08 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:08 volumio sudo[29963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:32:08 volumio sudo[29963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:09 volumio sudo[29965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:32:09 volumio sudo[29965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:09 volumio volumio[29789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:32:09 volumio sudo[29965]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:09 volumio volumio[29789]: info: ___________ START PLUGINS ___________ Feb 10 13:32:09 volumio sudo[29967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:32:09 volumio volumio[29789]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:32:09 volumio volumio[29789]: info: Creating MPD Configuration file Feb 10 13:32:09 volumio sudo[29967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:09 volumio volumio[29789]: info: [1770705129114] CoreMusicLibrary::Adding element Media Servers Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:09 volumio volumio[29789]: info: UPNP Browser: Client initialized successfully Feb 10 13:32:09 volumio sudo[29976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:32:09 volumio sudo[29963]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:09 volumio sudo[29976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:09 volumio sudo[29978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:32:09 volumio sudo[29978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:32:09 volumio sudo[29976]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:09 volumio volumio[29789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:09 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:32:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:32:09 volumio systemd[1]: mpd.service: Consumed 7.155s CPU time. Feb 10 13:32:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:32:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:32:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:32:09 volumio volumio[29789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:09 volumio volumio[29789]: info: [1770705129472] CoreMusicLibrary::Adding element Last_100 Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:32:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:09 volumio volumio[29789]: info: [1770705129512] CoreMusicLibrary::Adding element Webradio Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:32:09 volumio volumio[29789]: info: Initializing BBC Radios Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:09 volumio volumio[29789]: info: Creating Spotify config file Feb 10 13:32:09 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:09 volumio sudo[29990]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:32:09 volumio sudo[29990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:32:10 volumio sudo[29990]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Feb 10 13:32:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:10 volumio go-librespot[30006]: go-librespot daemon starting... Feb 10 13:32:10 volumio go-librespot[30007]: time="2026-02-10T13:32:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:11 volumio volumio[29913]: Starting albumart workers Feb 10 13:32:11 volumio go-librespot[30007]: time="2026-02-10T13:32:11+07:00" level=info msg="zeroconf server listening on port 35233" Feb 10 13:32:11 volumio volumio[29789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:11 volumio volumio[29789]: info: [1770705131341] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:32:11 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:11 volumio volumio[29789]: Cannot find translation for source YouTube Music Feb 10 13:32:11 volumio volumio[29916]: Starting albumart workers Feb 10 13:32:11 volumio volumio[29917]: Starting albumart workers Feb 10 13:32:11 volumio volumio[29789]: info: Volumio Calling Home Feb 10 13:32:11 volumio sudo[30015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:32:11 volumio sudo[30015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:11 volumio sudo[30015]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:12 volumio volumio[29789]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:32:12 volumio volumio[29789]: info: Discovery: Found device Volumio Feb 10 13:32:12 volumio volumio[29789]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:12 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:12 volumio volumio[29789]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:32:12 volumio volumio[29789]: info: Discovery: Found device Volumio Feb 10 13:32:12 volumio volumio[29789]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:12 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:12 volumio volumio[29789]: info: MPD Permissions set Feb 10 13:32:12 volumio volumio[29789]: info: MPD Permissions set Feb 10 13:32:12 volumio volumio[29789]: info: Upmpdcli Daemon Started Feb 10 13:32:12 volumio volumio[29789]: info: Spotify config file written Feb 10 13:32:12 volumio sudo[30027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:32:12 volumio sudo[30027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:12 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 13:32:12 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 13:32:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:13 volumio go-librespot[30029]: go-librespot daemon starting... Feb 10 13:32:13 volumio sudo[30027]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+07:00" level=debug msg="app state loaded" Feb 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:13 volumio volumio[29789]: 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 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:13 volumio volumio[29789]: info: No need to fix Spotify hosts Feb 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+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 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+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 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+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 10 13:32:13 volumio go-librespot[30030]: time="2026-02-10T13:32:13+07:00" level=info msg="zeroconf server listening on port 36913" Feb 10 13:32:13 volumio volumio[29789]: info: Volumio called home Feb 10 13:32:14 volumio go-librespot[30030]: time="2026-02-10T13:32:14+07:00" level=debug msg="obtained new client token: AABUGW+nwghcoa5P5m13mgOelWWYDvAJLH+/7x6HzF+NQ7kGvML7l/5NQ/bap8oh6Ek1lIFqmwA4KnueGouvfNsSF8YBL3fKze9VrZrj4++IoJEK4LGzsRdO2HoOxbfpxSGgEjtLkHAG9DQ2n/A9kV53hPTF4M0f4pRlLMkQnkIPHie5KgkF8mRTACbZmF00UGHXotO9FF47E05WuEuWdPXb55pCB8+RbTF1S2UtQRrhL5YXikR4bYg=" Feb 10 13:32:14 volumio volumio[29789]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:32:14 volumio volumio[29789]: SPOTIFY: BQCQNq5J3YJg1r23B8dUX0y0Zbhm4MXTKISNVaNSSngiON3LQNJ-nYN05BcerxIo9SbH6O1zpBqGh_LLTCZqkoPjoVdanxwu-i6iqf0hBffLn00GtNSNq4KIuAEaLDEWz7fC0NbI147p6TkSpr56SULJ-2Z6FgLT50r026QKYSWMKJXoBd4zKbBXF84gizS865WH--TqCHd97ukhkwwirdRTgvb5-xvDWE51BYAnHlfzBLSWmaP2N2WFIgudFSk9GqhmG0wgejl2njswPbhEHUpi1AxiE7rBp7tw4-0ZAnrFYauMKqYYwi9C Feb 10 13:32:14 volumio volumio[29789]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:32:14 volumio volumio[29789]: info: New Spotify access token = BQCQNq5J3YJg1r23B8dUX0y0Zbhm4MXTKISNVaNSSngiON3LQNJ-nYN05BcerxIo9SbH6O1zpBqGh_LLTCZqkoPjoVdanxwu-i6iqf0hBffLn00GtNSNq4KIuAEaLDEWz7fC0NbI147p6TkSpr56SULJ-2Z6FgLT50r026QKYSWMKJXoBd4zKbBXF84gizS865WH--TqCHd97ukhkwwirdRTgvb5-xvDWE51BYAnHlfzBLSWmaP2N2WFIgudFSk9GqhmG0wgejl2njswPbhEHUpi1AxiE7rBp7tw4-0ZAnrFYauMKqYYwi9C Feb 10 13:32:14 volumio volumio[29789]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:32:14 volumio go-librespot[30030]: time="2026-02-10T13:32:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:14 volumio volumio[29789]: info: Starting Shairport Sync Feb 10 13:32:14 volumio volumio[29789]: info: Starting Shairport Sync Feb 10 13:32:14 volumio go-librespot[30030]: time="2026-02-10T13:32:14+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:14 volumio volumio[29789]: info: Starting Shairport Sync Feb 10 13:32:14 volumio go-librespot[30030]: time="2026-02-10T13:32:14+07:00" level=debug msg="completed challenge" Feb 10 13:32:14 volumio sudo[30063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:32:14 volumio sudo[30063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:14 volumio sudo[30061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:32:14 volumio go-librespot[30030]: time="2026-02-10T13:32:14+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 10 13:32:14 volumio sudo[30061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:14 volumio sudo[30065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:32:14 volumio sudo[30065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:32:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:32:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:32:14 volumio systemd[1]: shairport-sync.service: Consumed 2.280s CPU time. Feb 10 13:32:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:32:14 volumio sudo[30063]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:14 volumio sudo[30061]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:32:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:32:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:32:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:32:14 volumio sudo[30065]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:14 volumio volumio[29789]: info: Shairport-Sync Started Feb 10 13:32:14 volumio volumio[29789]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:32:14 volumio volumio[29789]: info: Shairport-Sync Started Feb 10 13:32:14 volumio volumio[29789]: info: Shairport-Sync Started Feb 10 13:32:14 volumio volumio[29789]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:14 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:15 volumio volumio[29789]: 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 10 13:32:15 volumio volumio[29789]: info: Spotify Successfully logged in Feb 10 13:32:15 volumio volumio[29789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:15 volumio volumio[29789]: info: [1770705135210] CoreMusicLibrary::Adding element Spotify Feb 10 13:32:15 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:15 volumio volumio[29789]: Cannot find translation for source YouTube Music Feb 10 13:32:15 volumio volumio[29789]: Cannot find translation for source Spotify Feb 10 13:32:15 volumio volumio[29789]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:32:15 volumio volumio[29789]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:32:16 volumio volumio[29789]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:32:16 volumio volumio[29789]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:16 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:16 volumio volumio[29789]: info: CoreStateMachine::pushState Feb 10 13:32:16 volumio volumio[29789]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:16 volumio volumio[29789]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:16 volumio volumio[29789]: info: go-librespot daemon successfully initialized Feb 10 13:32:17 volumio mpd[30005]: 2026-02-10T13:32:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:32:17 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:32:17 volumio sudo[29967]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:17 volumio sudo[29978]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:17 volumio volumio[29789]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:32:17 volumio volumio[29789]: assert.ok(self.idling) Feb 10 13:32:17 volumio volumio[29789]: error: The expression evaluated to a falsy value: Feb 10 13:32:17 volumio volumio[29789]: assert.ok(self.idling) Feb 10 13:32:17 volumio volumio[29789]: error: updateQueue error: null Feb 10 13:32:17 volumio volumio[29789]: info: MPD running with PID30005 Feb 10 13:32:17 volumio volumio[29789]: ,establishing connection Feb 10 13:32:17 volumio volumio[29789]: info: Completed starting Core Plugins Feb 10 13:32:17 volumio volumio[29789]: info: ------------------------------------------- Feb 10 13:32:17 volumio volumio[29789]: info: ----- MyVolumio plugins startup ---- Feb 10 13:32:17 volumio volumio[29789]: info: ------------------------------------------- Feb 10 13:32:17 volumio volumio[29789]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:32:17 volumio volumio[29789]: error: updateQueue error: null Feb 10 13:32:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 13:32:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:17 volumio go-librespot[30106]: go-librespot daemon starting... Feb 10 13:32:17 volumio go-librespot[30107]: time="2026-02-10T13:32:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:17 volumio go-librespot[30107]: time="2026-02-10T13:32:17+07:00" level=debug msg="app state loaded" Feb 10 13:32:17 volumio go-librespot[30107]: time="2026-02-10T13:32:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+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 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+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 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+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 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+07:00" level=info msg="zeroconf server listening on port 35373" Feb 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+07:00" level=debug msg="obtained new client token: AACrQIjkQWPsnPmadJqIWiyWnds0tOJmWpQ+Xs8Xtx30MTlRC+rrB8dl2TYoFn4vt52sLd1dSaqtLijtNkkm1JQcTnMrP6v7tC7Nhw7W0brjfowalLl4KOhSsSJj8l2YgEdYe6nR/cxz9g3feYUSABzRCdbm3DaoDBPTeOHWYhIG5Z8d2Hyk8VZWXfPOi/rXF/64u+CD+fmYA/ojj+Inuv1b6nOWMN3+py1aWJgeL1dDK6gyH6/1D1LKbA==" Feb 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:18 volumio go-librespot[30107]: time="2026-02-10T13:32:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:32:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:19 volumio volumio[29789]: info: Initializing connection to go-librespot Websocket Feb 10 13:32:19 volumio volumio[29789]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:32:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 13:32:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:21 volumio go-librespot[30114]: go-librespot daemon starting... Feb 10 13:32:21 volumio go-librespot[30115]: time="2026-02-10T13:32:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:21 volumio go-librespot[30115]: time="2026-02-10T13:32:21+07:00" level=debug msg="app state loaded" Feb 10 13:32:21 volumio go-librespot[30115]: time="2026-02-10T13:32:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:22 volumio volumio[29789]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+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 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+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 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+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 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+07:00" level=info msg="zeroconf server listening on port 45919" Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+07:00" level=debug msg="obtained new client token: AABvanqQ4wJ+xmd9JRj9op1W1+a+CYipJGKWkFrvuEncWY47Z/5OUrKrnLgXlR/8lLvlgkB7ZOhCIkZgzjrs0J7xkd+pPhbWpxUb/VVeTC5VD33wWSlm/AZP5JbK8aYFfRWq8armRqrvtO7NVltVGJpMKAfeh0LBpZocYK0c9dZiv8p5V4lAAmUTZjo4bYcXkfUXBGbzcgl4UyIBnRi6pxdv119/iOxiF59lO/W3BVQo9f/L+VtHHVX85A==" Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+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 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+07:00" level=debug msg="completed challenge" Feb 10 13:32:22 volumio volumio[29789]: info: Initializing connection to go-librespot Websocket Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+07:00" level=debug msg="new websocket client" Feb 10 13:32:22 volumio volumio[29789]: info: Connection to go-librespot Websocket established Feb 10 13:32:22 volumio go-librespot[30115]: time="2026-02-10T13:32:22+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 10 13:32:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:23 volumio volumio[29789]: info: Connection to go-librespot Websocket closed Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 13:32:25 volumio volumio[29789]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 13:32:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 13:32:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:26 volumio go-librespot[30123]: go-librespot daemon starting... Feb 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+07:00" level=debug msg="app state loaded" Feb 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+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 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+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 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+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 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+07:00" level=info msg="zeroconf server listening on port 43575" Feb 10 13:32:26 volumio go-librespot[30124]: time="2026-02-10T13:32:26+07:00" level=debug msg="obtained new client token: AAD/9dB62YCRjIWqQEmDwS7L1NjM7o4g38ljvVcZ06Ggg/L5TEjtX6MevKlwaPs4lHBVgZFS78UWPd/6J2jYD87BhkWXahEVOqi/MKaSFYGK3wMgizuMuaDWTaZEMllFRC9oLBHg4COQ8B7WlFljVoSgalgYPT/dgdyzh+3KQRhIAXUGSigyulxvs8UvOn6Jwh7SZ5SoKMxG4Hd2acasMlW9TABIrNgpUmo8hJpMBvmO5alfddtr8CEvBQ==" Feb 10 13:32:27 volumio go-librespot[30124]: time="2026-02-10T13:32:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:27 volumio go-librespot[30124]: time="2026-02-10T13:32:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:32:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:27 volumio volumio[29789]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 13:32:27 volumio volumio[29789]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 13:32:27 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:27 volumio volumio[29789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:27 volumio volumio[29789]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 13:32:27 volumio volumio[29789]: info: MyVolumio login type: Token Feb 10 13:32:27 volumio volumio[29789]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 13:32:27 volumio volumio[29789]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 13:32:29 volumio volumio[29789]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 13:32:29 volumio volumio[29789]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 13:32:29 volumio volumio[29789]: info: Streaming services startup Feb 10 13:32:29 volumio volumio[29789]: info: Starting Streaming Daemon Feb 10 13:32:29 volumio sudo[30149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 13:32:29 volumio sudo[30149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:29 volumio volumio[29789]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 13:32:29 volumio sudo[30149]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:29 volumio volumio[29789]: info: Getting Spotify volume Feb 10 13:32:29 volumio volumio[29789]: info: Initializing connection to go-librespot Websocket Feb 10 13:32:29 volumio volumio[29789]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:32:29 volumio volumio[29789]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:32:29 volumio volumio[29789]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 13:32:29 volumio volumio[29789]: errno: -111, Feb 10 13:32:29 volumio volumio[29789]: code: 'ECONNREFUSED', Feb 10 13:32:29 volumio volumio[29789]: syscall: 'connect', Feb 10 13:32:29 volumio volumio[29789]: address: '127.0.0.1', Feb 10 13:32:29 volumio volumio[29789]: port: 9879, Feb 10 13:32:29 volumio volumio[29789]: response: undefined Feb 10 13:32:29 volumio volumio[29789]: } Feb 10 13:32:29 volumio volumio[29789]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:32:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 13:32:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:30 volumio go-librespot[30167]: go-librespot daemon starting... Feb 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+07:00" level=debug msg="app state loaded" Feb 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+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 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+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 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+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 10 13:32:30 volumio go-librespot[30168]: time="2026-02-10T13:32:30+07:00" level=info msg="zeroconf server listening on port 39905" Feb 10 13:32:31 volumio go-librespot[30168]: time="2026-02-10T13:32:31+07:00" level=debug msg="obtained new client token: AAA6Nyds9mdjzigv8yQEVQk+ILF9Pc5reZ1MBPt2t4qdH0usLNG+N21kNswEZ7D1w+/MdETo88pmr3H611FOXpkjtwu4l3tzhZw/zFS3YcX3o5GefOYXtNNWml4pSfHIMoNSXhO9K1HK83iRmsU+bTlVBHzSSuAi3f1hQQb6Y+RtQcmTnGJ0o/UotjuARqGc62ILshoR+GOusm5OzWB3Pqy2mdlmmQc/wV0nxN8ZMX88Wb9JtKtUsk8=" Feb 10 13:32:31 volumio sudo[30180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:31' Feb 10 13:32:31 volumio sudo[30180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:31 volumio go-librespot[30168]: time="2026-02-10T13:32:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:31 volumio go-librespot[30168]: time="2026-02-10T13:32:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:32:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:31 volumio sudo[30180]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:33 volumio volumio-remote-updater[643]: [2026-02-10 13:32:33] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 13:32:33 volumio volumio-remote-updater[643]: [2026-02-10 13:32:33] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 13:32:33 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:33 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 13:32:33 volumio systemd[1]: volumio.service: Consumed 55.186s CPU time. Feb 10 13:32:33 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:32:33 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:32:33 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10304. Feb 10 13:32:33 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:32:33 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 13:32:33 volumio systemd[1]: volumio.service: Consumed 55.186s CPU time. Feb 10 13:32:33 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 13:32:33 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:32:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 13:32:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:34 volumio go-librespot[30210]: go-librespot daemon starting... Feb 10 13:32:34 volumio go-librespot[30211]: time="2026-02-10T13:32:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:34 volumio go-librespot[30211]: time="2026-02-10T13:32:34+07:00" level=debug msg="app state loaded" Feb 10 13:32:34 volumio go-librespot[30211]: time="2026-02-10T13:32:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+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 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+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 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+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 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+07:00" level=info msg="zeroconf server listening on port 45791" Feb 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+07:00" level=debug msg="obtained new client token: AABwfNyMwjsWqNLrZ2H8+cIMe/4M87Md0AljPGM/4cq7mMGJzOvfTtgdr/BdkNZe2uL8NYxwhC9tlgSpwbw4MecJ5zaVfINIqZqYZYuvEwVJSaMmEmETf3fDjn7lA/j6cOCaDszay4JNE3PmvwJGEdAo0xzhYWtlLhrPKx4cMPG8ufjZAPU+A7noBxRDJQCEBwEqdBEd2Pub6NmsDUUlnGgzTXB6dTez7KxHFqI/40QODCbB0NXDpfRP7w==" Feb 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+07:00" level=debug msg="completed challenge" Feb 10 13:32:35 volumio go-librespot[30211]: time="2026-02-10T13:32:35+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 10 13:32:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:36 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:32:36 volumio volumio[30195]: info: ----- Volumio3 ---- Feb 10 13:32:36 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:32:36 volumio volumio[30195]: info: ----- System startup ---- Feb 10 13:32:36 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:32:38 volumio volumio-remote-updater[643]: [2026-02-10 13:32:38] [connect] Successful connection Feb 10 13:32:38 volumio volumio[30195]: info: MYVOLUMIO Environment detected Feb 10 13:32:38 volumio volumio[30195]: info: Plugin folders cleanup Feb 10 13:32:38 volumio volumio[30195]: info: Scanning into folder /volumio/app/plugins/ Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category audio_interface Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category miscellanea Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category music_service Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category plugins.json Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category system_controller Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category user_interface Feb 10 13:32:38 volumio volumio[30195]: info: Scanning into folder /data/plugins/ Feb 10 13:32:38 volumio volumio[30195]: info: Scanning category music_service Feb 10 13:32:38 volumio volumio[30195]: info: Plugin folders cleanup completed Feb 10 13:32:38 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:32:38 volumio volumio[30195]: info: ----- Core plugins startup ---- Feb 10 13:32:38 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:32:38 volumio volumio[30195]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 13:32:38 volumio volumio[30195]: info: Adding plugin upnp to MyMusic Plugins Feb 10 13:32:38 volumio volumio[30195]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 13:32:38 volumio volumio[30195]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 13:32:38 volumio volumio[30195]: info: Loading plugins from folder /data/plugins/ Feb 10 13:32:38 volumio volumio[30195]: info: Loading plugin "system"... Feb 10 13:32:38 volumio volumio[30195]: info: Loading plugin "appearance"... Feb 10 13:32:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 13:32:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:38 volumio go-librespot[30231]: go-librespot daemon starting... Feb 10 13:32:38 volumio go-librespot[30232]: time="2026-02-10T13:32:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:38 volumio go-librespot[30232]: time="2026-02-10T13:32:38+07:00" level=debug msg="app state loaded" Feb 10 13:32:38 volumio go-librespot[30232]: time="2026-02-10T13:32:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+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 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+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 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+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 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+07:00" level=info msg="zeroconf server listening on port 40235" Feb 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+07:00" level=debug msg="obtained new client token: AAD3RurL1MU+Dn2t7rJ0cfTx1dcRVs/+yR+GeR5CBs2W9C5kh/3qcqtBWnUlWofUKXH6GOSUbbX19zaM3JMUDJRHdjf05KsQS9cXpmxSQeq/h57cQBqxKG+242G9PxLe0fVnYE1aIzEVBYHMsl+M5JVkC2zNXGfZzmcUD9fl7AQgKoD68zsb68DxBeNRTfyE4k6DQcKBKP5StyEIRObX0POiIPMJ+geLGSfEeEB4NGiE3GBwS2KIpgxH/Q==" Feb 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+07:00" level=debug msg="completed challenge" Feb 10 13:32:39 volumio go-librespot[30232]: time="2026-02-10T13:32:39+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 10 13:32:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "network"... Feb 10 13:32:40 volumio volumio[30195]: info: Refreshing Cached IP Addresses Feb 10 13:32:40 volumio sudo[30240]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:32:40 volumio sudo[30240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:40 volumio sudo[30240]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:40 volumio sudo[30242]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "services"... Feb 10 13:32:40 volumio sudo[30242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "alsa_controller"... Feb 10 13:32:40 volumio sudo[30242]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:40 volumio sudo[30250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 13:32:40 volumio sudo[30250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:40 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "wizard"... Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "networkfs"... Feb 10 13:32:40 volumio volumio[30195]: info: Starting Udev Watcher for removable devices Feb 10 13:32:40 volumio volumio[30195]: info: Ignoring mount for partition: boot Feb 10 13:32:40 volumio volumio[30195]: info: Ignoring mount for partition: volumio Feb 10 13:32:40 volumio volumio[30195]: info: Ignoring mount for partition: volumio_data Feb 10 13:32:40 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "volumio_command_line_client"... Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "upnp"... Feb 10 13:32:40 volumio volumio[30195]: info: [1770705160810] Starting Upmpd Daemon Feb 10 13:32:40 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "my_music"... Feb 10 13:32:40 volumio volumio[30195]: info: Loading plugin "mpd"... Feb 10 13:32:41 volumio volumio[30195]: info: Loading plugin "upnp_browser"... Feb 10 13:32:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 13:32:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:43 volumio go-librespot[30273]: go-librespot daemon starting... Feb 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+07:00" level=debug msg="app state loaded" Feb 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:43 volumio sudo[30250]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+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 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+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 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+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 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+07:00" level=info msg="zeroconf server listening on port 33785" Feb 10 13:32:43 volumio go-librespot[30274]: time="2026-02-10T13:32:43+07:00" level=debug msg="obtained new client token: AABHRL06V2MbAAP5K2mzheGE4GlhKoWt96KYy4Wf+qJo7PtaPwpIHpzFfSD5Nfs52jhyA8efRa5G+dJFWeqGcdEZB6OuuAPQ1ZJ4HqrtCp+Ho3Y1SacSE3cxxbcBe8F92kgHbKpxShVqVPAQiC4CQloQpAKN0W1L5DWi9XBvrDFBkqlM/LKCm2il2z5uqZc7S/p0Vhp7+fBpA0Kxg8N1rN3m4tLL5x7W2MtdlbeHtvvk7LfX9RKhZC+1+g==" Feb 10 13:32:44 volumio go-librespot[30274]: time="2026-02-10T13:32:44+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 10 13:32:44 volumio go-librespot[30274]: time="2026-02-10T13:32:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 13:32:44 volumio go-librespot[30274]: time="2026-02-10T13:32:44+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:44 volumio go-librespot[30274]: time="2026-02-10T13:32:44+07:00" level=debug msg="completed challenge" Feb 10 13:32:44 volumio go-librespot[30274]: time="2026-02-10T13:32:44+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 10 13:32:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:44 volumio volumio[30195]: info: Starting UPNP Browser Feb 10 13:32:44 volumio volumio[30195]: info: Loading plugin "alarm-clock"... Feb 10 13:32:44 volumio volumio[30195]: info: Loading plugin "airplay_emulation"... Feb 10 13:32:44 volumio volumio[30195]: info: Starting Shairport Sync Feb 10 13:32:44 volumio volumio[30195]: info: Loading plugin "last_100"... Feb 10 13:32:44 volumio volumio[30195]: info: Loading plugin "webradio"... Feb 10 13:32:44 volumio volumio[30195]: info: Loading plugin "i2s_dacs"... Feb 10 13:32:44 volumio volumio[30195]: info: Loading plugin "volumiodiscovery"... Feb 10 13:32:45 volumio volumio[30195]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:45 volumio volumio[30195]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:45 volumio volumio[30195]: *** WARNING *** For more information see Feb 10 13:32:45 volumio volumio[30195]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:45 volumio volumio[30195]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:45 volumio volumio[30195]: *** WARNING *** For more information see Feb 10 13:32:45 volumio node[30195]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:45 volumio node[30195]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:45 volumio node[30195]: *** WARNING *** For more information see Feb 10 13:32:45 volumio node[30195]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:32:45 volumio node[30195]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:32:45 volumio node[30195]: *** WARNING *** For more information see Feb 10 13:32:45 volumio volumio[30195]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:32:45 volumio volumio[30195]: info: Discovery: Started advertising with name: Volumio Feb 10 13:32:45 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:32:45 volumio volumio[30195]: info: Loading plugin "spop"... Feb 10 13:32:46 volumio volumio[30195]: info: Loading plugin "ytcr"... Feb 10 13:32:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 13:32:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:47 volumio go-librespot[30286]: go-librespot daemon starting... Feb 10 13:32:47 volumio go-librespot[30287]: time="2026-02-10T13:32:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:47 volumio go-librespot[30287]: time="2026-02-10T13:32:47+07:00" level=debug msg="app state loaded" Feb 10 13:32:47 volumio go-librespot[30287]: time="2026-02-10T13:32:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+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 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+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 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+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 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+07:00" level=info msg="zeroconf server listening on port 46711" Feb 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+07:00" level=debug msg="obtained new client token: AAARQKZOfg8Edp50wtzX3O/PzGov7fXN5V/CRTz5xuehC3cUnpVVG7SYM3xgQWFWNkGWcFeJm17LD4cSv8Ln4sg85qg/lA+ctwelelTwlPHBulHDaEgC/ZhWZ476ulTqZj7Nu1CaQv47MJufo0v0Q9BlUEV+PZSq6nDCVOQg1Xi2mn61k4Ehz705OoZht6gjhreGcK3Rmf+XaKvJD05E6Ab+vUW77ST5QQkA04BnaXj5qMIOyIWIWmsE+A==" Feb 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+07:00" level=debug msg="completed challenge" Feb 10 13:32:48 volumio go-librespot[30287]: time="2026-02-10T13:32:48+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 10 13:32:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:49 volumio volumio[30195]: info: Loading plugin "ytmusic"... Feb 10 13:32:50 volumio volumio-remote-updater[643]: [2026-02-10 13:32:50] [connect] Successful connection Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "outputs"... Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "albumart"... Feb 10 13:32:50 volumio volumio[30195]: info: Plugin example_plugin is not enabled Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "inputs"... Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "updater_comm"... Feb 10 13:32:50 volumio volumio[30195]: info: Plugin mpdemulation is not enabled Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "rest_api"... Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "websocket"... Feb 10 13:32:50 volumio volumio[30195]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:32:50 volumio volumio[30195]: info: Loading plugin "RoonBridge"... Feb 10 13:32:51 volumio volumio[30195]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:32:51 volumio volumio[30195]: info: Loading i18n strings for locale en Feb 10 13:32:51 volumio volumio[30195]: Updating browse sources language Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::initPlayerControls Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:32:51 volumio volumio[30195]: Express server listening on port 3000 Feb 10 13:32:51 volumio volumio[30195]: [Metrics] WebUI: 15s 797.90ms Feb 10 13:32:51 volumio volumio[30195]: info: CoreStateMachine::resetVolumioState Feb 10 13:32:51 volumio volumio[30195]: info: CoreStateMachine::getcurrentVolume Feb 10 13:32:51 volumio volumio[30195]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:32:51 volumio volumio[30308]: Forking 3 albumart workers Feb 10 13:32:51 volumio sudo[30324]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:32:51 volumio sudo[30324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:51 volumio sudo[30324]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:51 volumio sudo[30328]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:32:51 volumio sudo[30328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:51 volumio sudo[30328]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:52 volumio volumio[30195]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:32:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 13:32:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:52 volumio go-librespot[30356]: go-librespot daemon starting... Feb 10 13:32:52 volumio go-librespot[30359]: time="2026-02-10T13:32:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:52 volumio go-librespot[30359]: time="2026-02-10T13:32:52+07:00" level=debug msg="app state loaded" Feb 10 13:32:52 volumio go-librespot[30359]: time="2026-02-10T13:32:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:52 volumio volumio[30195]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::pushState Feb 10 13:32:52 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::updateTrackBlock Feb 10 13:32:52 volumio volumio[30195]: info: CorePlayQueue::getTrackBlock Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:32:52 volumio volumio-remote-updater[643]: [2026-02-10 13:32:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770705170 101 Feb 10 13:32:52 volumio volumio[30195]: 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 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:52 volumio volumio[30195]: info: Reloading queue from file Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::pushState Feb 10 13:32:52 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::setRandom null Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::pushState Feb 10 13:32:52 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:52 volumio volumio[30195]: info: Setting Device type: Raspberry PI Feb 10 13:32:52 volumio volumio[30195]: info: Completed loading Core Plugins Feb 10 13:32:52 volumio volumio[30195]: info: Preparing to generate the ALSA configuration file Feb 10 13:32:52 volumio volumio[30195]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:32:52 volumio volumio[30195]: info: CoreStateMachine::pushState Feb 10 13:32:52 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:52 volumio volumio[30195]: info: CoreCommandRouter::volumioPushState Feb 10 13:32:52 volumio volumio[30195]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:32:52 volumio volumio[30195]: info: Output device has changed, restarting MPD Feb 10 13:32:52 volumio sudo[30377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:32:52 volumio go-librespot[30359]: time="2026-02-10T13:32:52+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 10 13:32:52 volumio go-librespot[30359]: time="2026-02-10T13:32:52+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 10 13:32:52 volumio go-librespot[30359]: time="2026-02-10T13:32:52+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 10 13:32:52 volumio sudo[30377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:53 volumio volumio[30195]: info: Output device has changed, restarting Shairport Sync Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:53 volumio go-librespot[30359]: time="2026-02-10T13:32:53+07:00" level=info msg="zeroconf server listening on port 43379" Feb 10 13:32:53 volumio sudo[30382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:32:53 volumio sudo[30382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:53 volumio sudo[30379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:32:53 volumio sudo[30379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:53 volumio sudo[30379]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:53 volumio volumio[30195]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:32:53 volumio volumio[30195]: info: ___________ START PLUGINS ___________ Feb 10 13:32:53 volumio volumio[30195]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:32:53 volumio volumio[30195]: info: Creating MPD Configuration file Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:53 volumio volumio[30195]: info: [1770705173215] CoreMusicLibrary::Adding element Media Servers Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:53 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:32:53 volumio volumio[30195]: info: UPNP Browser: Client initialized successfully Feb 10 13:32:53 volumio go-librespot[30359]: time="2026-02-10T13:32:53+07:00" level=debug msg="obtained new client token: AACVEXTTRSPPeKAZTgTMmg2tqcsdnp3R1fo1jk1xK36AFM6UVM1JpqyMqbNjOooE38N6koBXcNhy1X0eR2BcQ8zMXFllZ7gzyx9tcBOENTiKzHbxOIHcrYR94Z9MgLe9jsW0ZYKUUcXIUOjWmZLxmEJyo+nLoo0MwK8F/xwZPznQtG6lJ/cULuKvdMyAMjWKOC9jmsfMvzHskOOi0DI8Q0ILUP4atoIgs6Wd5mbN43IyVj4m8YeIJ/c=" Feb 10 13:32:53 volumio sudo[30390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:32:53 volumio sudo[30390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:53 volumio sudo[30377]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:53 volumio sudo[30390]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:53 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:32:53 volumio go-librespot[30359]: time="2026-02-10T13:32:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:32:53 volumio systemd[1]: mpd.service: Consumed 7.264s CPU time. Feb 10 13:32:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:32:53 volumio sudo[30392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:32:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:32:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:32:53 volumio sudo[30392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:53 volumio volumio[30195]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:53 volumio go-librespot[30359]: time="2026-02-10T13:32:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:32:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:32:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:53 volumio volumio[30195]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:53 volumio volumio[30195]: info: [1770705173598] CoreMusicLibrary::Adding element Last_100 Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:53 volumio volumio[30195]: info: [1770705173617] CoreMusicLibrary::Adding element Webradio Feb 10 13:32:53 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:32:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:32:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:32:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:32:53 volumio volumio[30195]: info: Initializing BBC Radios Feb 10 13:32:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:32:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:53 volumio volumio[30195]: info: Creating Spotify config file Feb 10 13:32:53 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:54 volumio sudo[30415]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:32:54 volumio sudo[30415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:32:54 volumio sudo[30415]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:55 volumio volumio[30323]: Starting albumart workers Feb 10 13:32:55 volumio volumio[30195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:55 volumio volumio[30195]: info: [1770705175173] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:32:55 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:55 volumio volumio[30195]: Cannot find translation for source YouTube Music Feb 10 13:32:55 volumio volumio[30195]: info: Volumio Calling Home Feb 10 13:32:55 volumio sudo[30423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:32:55 volumio sudo[30423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:55 volumio sudo[30423]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:55 volumio volumio[30327]: Starting albumart workers Feb 10 13:32:55 volumio volumio[30325]: Starting albumart workers Feb 10 13:32:56 volumio volumio[30195]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:32:56 volumio volumio[30195]: info: Discovery: Found device Volumio Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:56 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:56 volumio volumio[30195]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:32:56 volumio volumio[30195]: info: Discovery: Found device Volumio Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:56 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:56 volumio volumio[30195]: info: MPD Permissions set Feb 10 13:32:56 volumio volumio[30195]: info: MPD Permissions set Feb 10 13:32:56 volumio volumio[30195]: info: Upmpdcli Daemon Started Feb 10 13:32:56 volumio volumio[30195]: info: Spotify config file written Feb 10 13:32:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 13:32:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:56 volumio sudo[30429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:32:56 volumio volumio[30195]: 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 10 13:32:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:56 volumio go-librespot[30430]: go-librespot daemon starting... Feb 10 13:32:56 volumio sudo[30429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio go-librespot[30431]: time="2026-02-10T13:32:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:56 volumio go-librespot[30431]: time="2026-02-10T13:32:56+07:00" level=debug msg="app state loaded" Feb 10 13:32:56 volumio go-librespot[30431]: time="2026-02-10T13:32:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:56 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:32:57 volumio go-librespot[30449]: go-librespot daemon starting... Feb 10 13:32:57 volumio sudo[30429]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:57 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:32:57 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:32:57 volumio volumio[30195]: info: No need to fix Spotify hosts Feb 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+07:00" level=debug msg="app state loaded" Feb 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:32:57 volumio volumio[30195]: info: Volumio called home Feb 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+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 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+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 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+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 10 13:32:57 volumio go-librespot[30455]: time="2026-02-10T13:32:57+07:00" level=info msg="zeroconf server listening on port 35635" Feb 10 13:32:58 volumio volumio[30195]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:32:58 volumio volumio[30195]: SPOTIFY: BQAt0gFmaftwcMDJdfuy6ma0kXaePtCLEpMakC1Ou1pr5Ng3htZCqMQjKttDi955jfikvqq9SvIGXXesnoQDf1gAQyA62kWjbrN2ft_G53SQantoWbQfrN1uTQSXREX1s0KEl-Sq_WtzLbGAEKkdGYu3ujrrNSVvlrKa5hngCjY28gIYzNx0Byj3T2nLwqO4V5sx7TyMbBcjZqEvAsocS5qKX_gIssLf3HN7WcsbPvaZk02dABHQp2qE-dM6A3lnPW7QHNgHwmhnPsIsTLsYVqgD9ucL-EoBwRSp5T2mEHIrjiCHK8MD4j9Q Feb 10 13:32:58 volumio volumio[30195]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:32:58 volumio volumio[30195]: info: New Spotify access token = BQAt0gFmaftwcMDJdfuy6ma0kXaePtCLEpMakC1Ou1pr5Ng3htZCqMQjKttDi955jfikvqq9SvIGXXesnoQDf1gAQyA62kWjbrN2ft_G53SQantoWbQfrN1uTQSXREX1s0KEl-Sq_WtzLbGAEKkdGYu3ujrrNSVvlrKa5hngCjY28gIYzNx0Byj3T2nLwqO4V5sx7TyMbBcjZqEvAsocS5qKX_gIssLf3HN7WcsbPvaZk02dABHQp2qE-dM6A3lnPW7QHNgHwmhnPsIsTLsYVqgD9ucL-EoBwRSp5T2mEHIrjiCHK8MD4j9Q Feb 10 13:32:58 volumio volumio[30195]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:32:58 volumio volumio[30195]: info: Starting Shairport Sync Feb 10 13:32:58 volumio volumio[30195]: info: Starting Shairport Sync Feb 10 13:32:58 volumio volumio[30195]: info: Starting Shairport Sync Feb 10 13:32:58 volumio go-librespot[30455]: time="2026-02-10T13:32:58+07:00" level=debug msg="obtained new client token: AAC4H1awRjfrBvJ7C5Ah2C3jW9mWLTvCq/D0UAGWVfx0QOEv/Yoh1YIwRehb7QKUdkJHoPKnrXAWLZ3hGF7ktPFSPsBIejq3VDu1yHMr48MJslvFpeUwiKEv8Y2abRzDaPBqi1lADug6H+J0mfZVwKMCR0WSLDeV/0chPIif03wZKI5+R0t4uBzdKmwzd/hCdCkgwiwAj4ey4HF+bWzWoeGBbebWd8an6nSaJnBSAmIX219qmlQtPEY=" Feb 10 13:32:58 volumio sudo[30475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:32:58 volumio sudo[30475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:58 volumio sudo[30477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:32:58 volumio sudo[30477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:58 volumio sudo[30479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:32:58 volumio go-librespot[30455]: time="2026-02-10T13:32:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:32:58 volumio sudo[30479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:32:58 volumio go-librespot[30455]: time="2026-02-10T13:32:58+07:00" level=debug msg="completed keyexchange" Feb 10 13:32:58 volumio go-librespot[30455]: time="2026-02-10T13:32:58+07:00" level=debug msg="completed challenge" Feb 10 13:32:58 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:32:58 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:32:58 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:32:58 volumio systemd[1]: shairport-sync.service: Consumed 2.317s CPU time. Feb 10 13:32:58 volumio go-librespot[30455]: time="2026-02-10T13:32:58+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 10 13:32:58 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:32:58 volumio sudo[30477]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:58 volumio sudo[30479]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:32:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:32:58 volumio sudo[30475]: pam_unix(sudo:session): session closed for user root Feb 10 13:32:58 volumio volumio[30195]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:58 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:58 volumio volumio[30195]: info: Shairport-Sync Started Feb 10 13:32:58 volumio volumio[30195]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:32:58 volumio volumio[30195]: info: Shairport-Sync Started Feb 10 13:32:58 volumio volumio[30195]: info: Shairport-Sync Started Feb 10 13:32:58 volumio volumio[30195]: 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 10 13:32:58 volumio volumio[30195]: info: Spotify Successfully logged in Feb 10 13:32:58 volumio volumio[30195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:32:58 volumio volumio[30195]: info: [1770705178924] CoreMusicLibrary::Adding element Spotify Feb 10 13:32:58 volumio volumio[30195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:32:58 volumio volumio[30195]: Cannot find translation for source YouTube Music Feb 10 13:32:58 volumio volumio[30195]: Cannot find translation for source Spotify Feb 10 13:32:59 volumio volumio[30195]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:32:59 volumio volumio[30195]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:32:59 volumio volumio[30195]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:32:59 volumio volumio[30195]: info: CoreCommandRouter::volumioGetState Feb 10 13:32:59 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:59 volumio volumio[30195]: info: CoreStateMachine::pushState Feb 10 13:32:59 volumio volumio[30195]: info: CorePlayQueue::getTrack 0 Feb 10 13:32:59 volumio volumio[30195]: info: CoreCommandRouter::volumioPushState Feb 10 13:33:01 volumio volumio[30195]: info: go-librespot daemon successfully initialized Feb 10 13:33:01 volumio mpd[30421]: 2026-02-10T13:33:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:33:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:33:01 volumio sudo[30382]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:01 volumio sudo[30392]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:01 volumio volumio[30195]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:33:01 volumio volumio[30195]: assert.ok(self.idling) Feb 10 13:33:01 volumio volumio[30195]: error: The expression evaluated to a falsy value: Feb 10 13:33:01 volumio volumio[30195]: assert.ok(self.idling) Feb 10 13:33:01 volumio volumio[30195]: info: MPD running with PID30421 Feb 10 13:33:01 volumio volumio[30195]: ,establishing connection Feb 10 13:33:01 volumio volumio[30195]: error: updateQueue error: null Feb 10 13:33:01 volumio volumio[30195]: info: Completed starting Core Plugins Feb 10 13:33:01 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:33:01 volumio volumio[30195]: info: ----- MyVolumio plugins startup ---- Feb 10 13:33:01 volumio volumio[30195]: info: ------------------------------------------- Feb 10 13:33:01 volumio volumio[30195]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:33:01 volumio volumio[30195]: error: updateQueue error: null Feb 10 13:33:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 13:33:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:01 volumio go-librespot[30520]: go-librespot daemon starting... Feb 10 13:33:01 volumio go-librespot[30521]: time="2026-02-10T13:33:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:01 volumio go-librespot[30521]: time="2026-02-10T13:33:01+07:00" level=debug msg="app state loaded" Feb 10 13:33:01 volumio go-librespot[30521]: time="2026-02-10T13:33:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+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 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+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 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+07:00" level=info msg="zeroconf server listening on port 46583" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+07:00" level=debug msg="obtained new client token: AADjuLpqd9UUTmC+j5LswWHAj0WxLnPd/WHV//CR7LitN/uEWwIJN2ecTZ/YxXZ43jl2eFKUqZhpxMnMOXxVTA+3NIzTOmCAibSSGvTgwQyenXFNRJ08U9rrf8WL6xIKD9kAwccrwc7gl+qhHXzcM58iZFtOttNxvd0ZZzvRNfTRwnnbQ4jEz+hvL6kkjMyI1rJdDBifG3vNrnAAzOc8OgQT7WRyGM1G7kpbA0q9eS7vkQDN3cUNdbFGrQ==" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+07:00" level=debug msg="completed challenge" Feb 10 13:33:02 volumio go-librespot[30521]: time="2026-02-10T13:33:02+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 10 13:33:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:04 volumio volumio[30195]: info: Initializing connection to go-librespot Websocket Feb 10 13:33:04 volumio volumio[30195]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:33:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 13:33:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:06 volumio go-librespot[30530]: go-librespot daemon starting... Feb 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+07:00" level=debug msg="app state loaded" Feb 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:06 volumio volumio[30195]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+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 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+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 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+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 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+07:00" level=info msg="zeroconf server listening on port 43543" Feb 10 13:33:06 volumio go-librespot[30531]: time="2026-02-10T13:33:06+07:00" level=debug msg="obtained new client token: AACLGRI3BNeSu3s4BTZp4sDa7G6fd7TNdYqFEOGVh4mvta7pMQiBLOpAVBrhrsu/LmSha0Yty4LPazrK2VT8oSUHrxf8Z/cVQzTOMhp8R3wjjVwfTX+6WaaOgHv8B0PEnPrVvB44glF4UKNsiwZtv+13cPDhTXc9Eaw/v2n2OurzBMYpxsqyL5sz3xS6JMgmvUzDZtRoZBsfraCdAUB9yq7LXZmfmYPzFFHiHw42l1hCc+d4uYo2JKI5bA==" Feb 10 13:33:07 volumio go-librespot[30531]: time="2026-02-10T13:33:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:07 volumio volumio[30195]: info: Initializing connection to go-librespot Websocket Feb 10 13:33:07 volumio go-librespot[30531]: time="2026-02-10T13:33:07+07:00" level=debug msg="new websocket client" Feb 10 13:33:07 volumio volumio[30195]: info: Connection to go-librespot Websocket established Feb 10 13:33:07 volumio go-librespot[30531]: time="2026-02-10T13:33:07+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:07 volumio go-librespot[30531]: time="2026-02-10T13:33:07+07:00" level=debug msg="completed challenge" Feb 10 13:33:07 volumio go-librespot[30531]: time="2026-02-10T13:33: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 10 13:33:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:07 volumio volumio[30195]: info: Connection to go-librespot Websocket closed Feb 10 13:33:10 volumio volumio[30195]: info: Getting Spotify volume Feb 10 13:33:10 volumio volumio[30195]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:33:10 volumio volumio[30195]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:33:10 volumio volumio[30195]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 13:33:10 volumio volumio[30195]: errno: -111, Feb 10 13:33:10 volumio volumio[30195]: code: 'ECONNREFUSED', Feb 10 13:33:10 volumio volumio[30195]: syscall: 'connect', Feb 10 13:33:10 volumio volumio[30195]: address: '127.0.0.1', Feb 10 13:33:10 volumio volumio[30195]: port: 9879, Feb 10 13:33:10 volumio volumio[30195]: response: undefined Feb 10 13:33:10 volumio volumio[30195]: } Feb 10 13:33:10 volumio volumio[30195]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:33:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 13:33:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:10 volumio go-librespot[30550]: go-librespot daemon starting... Feb 10 13:33:10 volumio go-librespot[30551]: time="2026-02-10T13:33:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:10 volumio go-librespot[30551]: time="2026-02-10T13:33:10+07:00" level=debug msg="app state loaded" Feb 10 13:33:10 volumio go-librespot[30551]: time="2026-02-10T13:33:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:10 volumio go-librespot[30551]: time="2026-02-10T13:33:10+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 10 13:33:10 volumio go-librespot[30551]: time="2026-02-10T13:33:10+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 10 13:33:10 volumio go-librespot[30551]: time="2026-02-10T13:33:10+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 10 13:33:11 volumio go-librespot[30551]: time="2026-02-10T13:33:10+07:00" level=info msg="zeroconf server listening on port 32807" Feb 10 13:33:11 volumio go-librespot[30551]: time="2026-02-10T13:33:11+07:00" level=debug msg="obtained new client token: AACyO7Ob7b9d430jVJV/1Bw0/yMy7/RfptAq4eTcFweeVLU5isNamCAKU4JFFlmHhMVYpkLYTA7LJ+1CSEjo/jzrSvhXRr33UBYi7/fzHFUDw4+MJ8uc2J7P4qiSeWi48nMOg5NeJbqG9g/W1nkbbZmJBKLG2P8bWR34jHSvn2oj7gK+3XxFVZapaJb5WoCLp9aRT9NK5va9tsYGEPqlpphbiiE8D+vnLE7LbrRVTBpqjoMWC/309K8=" Feb 10 13:33:11 volumio go-librespot[30551]: time="2026-02-10T13:33:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:11 volumio go-librespot[30551]: time="2026-02-10T13:33:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:33:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:11 volumio sudo[30576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:32' Feb 10 13:33:11 volumio sudo[30576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:11 volumio sudo[30576]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:12 volumio volumio-remote-updater[643]: [2026-02-10 13:33:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 13:33:12 volumio volumio-remote-updater[643]: [2026-02-10 13:33:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 13:33:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 13:33:12 volumio systemd[1]: volumio.service: Consumed 49.233s CPU time. Feb 10 13:33:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:33:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:33:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10305. Feb 10 13:33:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:33:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 13:33:12 volumio systemd[1]: volumio.service: Consumed 49.233s CPU time. Feb 10 13:33:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 13:33:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:33:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 13:33:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:14 volumio go-librespot[30605]: go-librespot daemon starting... Feb 10 13:33:14 volumio go-librespot[30606]: time="2026-02-10T13:33:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:14 volumio go-librespot[30606]: time="2026-02-10T13:33:14+07:00" level=debug msg="app state loaded" Feb 10 13:33:14 volumio go-librespot[30606]: time="2026-02-10T13:33:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+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 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+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 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+07:00" level=info msg="zeroconf server listening on port 46853" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+07:00" level=debug msg="obtained new client token: AAAdD1TIKW1JIH77eLZD/HGq6kYpcsKEUc73xBjAhrnvKhcfhRPQJlAXOd2YVZtwTs404DlcozrNzdn/eO29BXYkH6ynBW2/4Cqopk090b1QRy7c7pln5wC1hqL5O0hQQgo9lKRA6UGpuuAyBbCwUNmslDruP2WckmFA92fXGQCQaQadzKjoCeoZPP8ddjv1Kcn8AGtRZ/oE9/w7h9Jisqn0Ek9gUgyR+MdNaCeymoGEgNuFpwonR0Pn7g==" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+07:00" level=debug msg="completed challenge" Feb 10 13:33:15 volumio go-librespot[30606]: time="2026-02-10T13:33:15+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 10 13:33:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:15 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:15 volumio volumio[30590]: info: ----- Volumio3 ---- Feb 10 13:33:15 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:15 volumio volumio[30590]: info: ----- System startup ---- Feb 10 13:33:15 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:17 volumio volumio-remote-updater[643]: [2026-02-10 13:33:17] [connect] Successful connection Feb 10 13:33:17 volumio volumio[30590]: info: MYVOLUMIO Environment detected Feb 10 13:33:17 volumio volumio[30590]: info: Plugin folders cleanup Feb 10 13:33:17 volumio volumio[30590]: info: Scanning into folder /volumio/app/plugins/ Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category audio_interface Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category miscellanea Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category music_service Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category plugins.json Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category system_controller Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category user_interface Feb 10 13:33:17 volumio volumio[30590]: info: Scanning into folder /data/plugins/ Feb 10 13:33:17 volumio volumio[30590]: info: Scanning category music_service Feb 10 13:33:17 volumio volumio[30590]: info: Plugin folders cleanup completed Feb 10 13:33:17 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:17 volumio volumio[30590]: info: ----- Core plugins startup ---- Feb 10 13:33:17 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:17 volumio volumio[30590]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 13:33:17 volumio volumio[30590]: info: Adding plugin upnp to MyMusic Plugins Feb 10 13:33:17 volumio volumio[30590]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 13:33:17 volumio volumio[30590]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 13:33:17 volumio volumio[30590]: info: Loading plugins from folder /data/plugins/ Feb 10 13:33:17 volumio volumio[30590]: info: Loading plugin "system"... Feb 10 13:33:17 volumio volumio[30590]: info: Loading plugin "appearance"... Feb 10 13:33:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 13:33:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:18 volumio go-librespot[30625]: go-librespot daemon starting... Feb 10 13:33:18 volumio go-librespot[30626]: time="2026-02-10T13:33:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:18 volumio go-librespot[30626]: time="2026-02-10T13:33:18+07:00" level=debug msg="app state loaded" Feb 10 13:33:18 volumio go-librespot[30626]: time="2026-02-10T13:33:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "network"... Feb 10 13:33:19 volumio volumio[30590]: info: Refreshing Cached IP Addresses Feb 10 13:33:19 volumio sudo[30634]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:33:19 volumio go-librespot[30626]: time="2026-02-10T13:33: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:33:19 volumio go-librespot[30626]: time="2026-02-10T13:33:19+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 10 13:33:19 volumio go-librespot[30626]: time="2026-02-10T13:33:19+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 10 13:33:19 volumio sudo[30636]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:33:19 volumio sudo[30636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:19 volumio sudo[30634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:19 volumio go-librespot[30626]: time="2026-02-10T13:33:19+07:00" level=info msg="zeroconf server listening on port 44675" Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "services"... Feb 10 13:33:19 volumio sudo[30634]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "alsa_controller"... Feb 10 13:33:19 volumio sudo[30636]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:19 volumio sudo[30641]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 13:33:19 volumio sudo[30641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:19 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "wizard"... Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "networkfs"... Feb 10 13:33:19 volumio volumio[30590]: info: Starting Udev Watcher for removable devices Feb 10 13:33:19 volumio go-librespot[30626]: time="2026-02-10T13:33:19+07:00" level=debug msg="obtained new client token: AABeoiE2erqbI+l9S//dcvr7kfB9Y4DDUR/S09JTmWkfissgNhSaqtHmumElwswRfoLYqMWszqFIwv4xKrsa/nmzExs/kFOiT4aK40lH8Cv81Ox0AgaDcN6JJMANntOpEvS740SxlzO4OOtMMoSaqLFBy9LwZj/OQDhlresq75rVj9pxIM72cg1hPlDrHhq/HlVxYAWGyJu9rphHvnF+pOUaZBoY637KHaBn7mWiEJiz6X+4A78OwYJcXQ==" Feb 10 13:33:19 volumio volumio[30590]: info: Ignoring mount for partition: boot Feb 10 13:33:19 volumio volumio[30590]: info: Ignoring mount for partition: volumio Feb 10 13:33:19 volumio volumio[30590]: info: Ignoring mount for partition: volumio_data Feb 10 13:33:19 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "volumio_command_line_client"... Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "upnp"... Feb 10 13:33:19 volumio volumio[30590]: info: [1770705199843] Starting Upmpd Daemon Feb 10 13:33:19 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "my_music"... Feb 10 13:33:19 volumio go-librespot[30626]: time="2026-02-10T13:33:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:19 volumio volumio[30590]: info: Loading plugin "mpd"... Feb 10 13:33:20 volumio volumio[30590]: info: Loading plugin "upnp_browser"... Feb 10 13:33:21 volumio go-librespot[30626]: time="2026-02-10T13:33:21+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:21 volumio go-librespot[30626]: time="2026-02-10T13:33:21+07:00" level=debug msg="completed challenge" Feb 10 13:33:21 volumio go-librespot[30626]: time="2026-02-10T13:33:21+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 10 13:33:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:22 volumio sudo[30641]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:23 volumio volumio[30590]: info: Starting UPNP Browser Feb 10 13:33:23 volumio volumio[30590]: info: Loading plugin "alarm-clock"... Feb 10 13:33:23 volumio volumio[30590]: info: Loading plugin "airplay_emulation"... Feb 10 13:33:23 volumio volumio[30590]: info: Starting Shairport Sync Feb 10 13:33:23 volumio volumio[30590]: info: Loading plugin "last_100"... Feb 10 13:33:23 volumio volumio[30590]: info: Loading plugin "webradio"... Feb 10 13:33:23 volumio volumio[30590]: info: Loading plugin "i2s_dacs"... Feb 10 13:33:23 volumio volumio[30590]: info: Loading plugin "volumiodiscovery"... Feb 10 13:33:24 volumio volumio[30590]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:33:24 volumio node[30590]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:33:24 volumio volumio[30590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:33:24 volumio node[30590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:33:24 volumio volumio[30590]: *** WARNING *** For more information see Feb 10 13:33:24 volumio node[30590]: *** WARNING *** For more information see Feb 10 13:33:24 volumio volumio[30590]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:33:24 volumio node[30590]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:33:24 volumio volumio[30590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:33:24 volumio node[30590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:33:24 volumio volumio[30590]: *** WARNING *** For more information see Feb 10 13:33:24 volumio node[30590]: *** WARNING *** For more information see Feb 10 13:33:24 volumio volumio[30590]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:33:24 volumio volumio[30590]: info: Discovery: Started advertising with name: Volumio Feb 10 13:33:24 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:33:24 volumio volumio[30590]: info: Loading plugin "spop"... Feb 10 13:33:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 13:33:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:24 volumio go-librespot[30670]: go-librespot daemon starting... Feb 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33:24+07:00" level=debug msg="app state loaded" Feb 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33: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 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33: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 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33: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 10 13:33:24 volumio go-librespot[30671]: time="2026-02-10T13:33:24+07:00" level=info msg="zeroconf server listening on port 42121" Feb 10 13:33:25 volumio go-librespot[30671]: time="2026-02-10T13:33:25+07:00" level=debug msg="obtained new client token: AAArvUBj51LF3ks1gwI+R0qJejVANmnxDUQhkZ78L5DmxMh32aFiQUBuhzIiUOO5rJbLQUfqQdBeV8avoJK1Q2cnLmeAE1ReCKhJvsm9gH2nlY8wpxdJNq1WkkVYL2KkkLGjIEcU3mwXps1ce51cWM3uk0fTNJW0R6gF7WVkaUlQD9U0M+G69rflbVD1acLsh2iDvfwVY/5oTYI6ADfqPR7xnhVhKAaCZnqHHoj9b4pNe2eVPv3BRz0=" Feb 10 13:33:25 volumio go-librespot[30671]: time="2026-02-10T13:33:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:25 volumio go-librespot[30671]: time="2026-02-10T13:33:25+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:25 volumio go-librespot[30671]: time="2026-02-10T13:33:25+07:00" level=debug msg="completed challenge" Feb 10 13:33:25 volumio go-librespot[30671]: time="2026-02-10T13:33: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 10 13:33:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:26 volumio volumio[30590]: info: Loading plugin "ytcr"... Feb 10 13:33:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 13:33:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:28 volumio volumio[30590]: info: Loading plugin "ytmusic"... Feb 10 13:33:28 volumio go-librespot[30679]: go-librespot daemon starting... Feb 10 13:33:28 volumio go-librespot[30680]: time="2026-02-10T13:33:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:28 volumio go-librespot[30680]: time="2026-02-10T13:33:28+07:00" level=debug msg="app state loaded" Feb 10 13:33:28 volumio go-librespot[30680]: time="2026-02-10T13:33:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+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 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+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 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+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 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+07:00" level=info msg="zeroconf server listening on port 36719" Feb 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+07:00" level=debug msg="obtained new client token: AABhxCzhM4I0LEbI9WPb5ngweJmN/xWbGSO1Fhul17yweIdl7JIu+9hQxXQH33If49RPL9Ckeoq5IMmKNebvf9H7hBYcP8rNkSEF9VcxullNOVUEAxqx0ZXYDpspkAe8Yu1PuNEp3DEWxwx4ooJTuUoI5NGYSkoT+V9wnnBcqlss6/n9s7d5ObWVCq1f8qFJtlCJwwpAOqVTrfAG8mnxhbFfWZCte1nxVnWydCSOgDBlAA3eVODMeYpgcA==" Feb 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:29 volumio volumio-remote-updater[643]: [2026-02-10 13:33:29] [connect] Successful connection Feb 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33:29+07:00" level=debug msg="completed challenge" Feb 10 13:33:29 volumio volumio[30590]: info: Loading plugin "outputs"... Feb 10 13:33:29 volumio volumio[30590]: info: Loading plugin "albumart"... Feb 10 13:33:29 volumio volumio[30590]: info: Plugin example_plugin is not enabled Feb 10 13:33:29 volumio volumio[30590]: info: Loading plugin "inputs"... Feb 10 13:33:29 volumio volumio[30590]: info: Loading plugin "updater_comm"... Feb 10 13:33:29 volumio go-librespot[30680]: time="2026-02-10T13:33: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 10 13:33:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:30 volumio volumio[30590]: info: Plugin mpdemulation is not enabled Feb 10 13:33:30 volumio volumio[30590]: info: Loading plugin "rest_api"... Feb 10 13:33:30 volumio volumio[30590]: info: Loading plugin "websocket"... Feb 10 13:33:30 volumio volumio[30590]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:33:30 volumio volumio[30590]: info: Loading plugin "RoonBridge"... Feb 10 13:33:30 volumio volumio[30590]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:33:30 volumio volumio[30590]: info: Loading i18n strings for locale en Feb 10 13:33:30 volumio volumio[30590]: Updating browse sources language Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:33:30 volumio volumio[30702]: Forking 3 albumart workers Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::initPlayerControls Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:33:30 volumio volumio[30590]: Express server listening on port 3000 Feb 10 13:33:30 volumio volumio[30590]: [Metrics] WebUI: 16s 38.08ms Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::resetVolumioState Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::getcurrentVolume Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:33:31 volumio sudo[30749]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:33:31 volumio sudo[30749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:31 volumio sudo[30749]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:31 volumio sudo[30751]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:33:31 volumio sudo[30751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:31 volumio sudo[30751]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:31 volumio volumio[30590]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:33:31 volumio volumio[30590]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::pushState Feb 10 13:33:31 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::volumioPushState Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::updateTrackBlock Feb 10 13:33:31 volumio volumio[30590]: info: CorePlayQueue::getTrackBlock Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:33:31 volumio volumio-remote-updater[643]: [2026-02-10 13:33:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770705209 101 Feb 10 13:33:31 volumio volumio[30590]: 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 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:31 volumio volumio[30590]: info: Reloading queue from file Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::pushState Feb 10 13:33:31 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::volumioPushState Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::setRandom null Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::pushState Feb 10 13:33:31 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::volumioPushState Feb 10 13:33:31 volumio volumio[30590]: info: Setting Device type: Raspberry PI Feb 10 13:33:31 volumio volumio[30590]: info: Completed loading Core Plugins Feb 10 13:33:31 volumio volumio[30590]: info: Preparing to generate the ALSA configuration file Feb 10 13:33:31 volumio volumio[30590]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:33:31 volumio volumio[30590]: info: CoreStateMachine::pushState Feb 10 13:33:31 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:31 volumio volumio[30590]: info: CoreCommandRouter::volumioPushState Feb 10 13:33:32 volumio volumio[30590]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:33:32 volumio volumio[30590]: info: Output device has changed, restarting MPD Feb 10 13:33:32 volumio nmbd[966]: [2026/02/10 13:33:32.100960, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 10 13:33:32 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 10 13:33:32 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 10 13:33:32 volumio volumio[30590]: info: Output device has changed, restarting Shairport Sync Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:32 volumio nmbd[966]: [2026/02/10 13:33:32.107737, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 10 13:33:32 volumio nmbd[966]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 10 13:33:32 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 10 13:33:32 volumio nmbd[966]: [2026/02/10 13:33:32.108515, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:32 volumio nmbd[966]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 10 13:33:32 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 10 13:33:32 volumio sudo[30764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:33:32 volumio sudo[30764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:32 volumio sudo[30766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:33:32 volumio sudo[30766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:32 volumio sudo[30766]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:32 volumio sudo[30768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:33:32 volumio volumio[30590]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:33:32 volumio volumio[30590]: info: ___________ START PLUGINS ___________ Feb 10 13:33:32 volumio sudo[30768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:32 volumio volumio[30590]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:33:32 volumio volumio[30590]: info: Creating MPD Configuration file Feb 10 13:33:32 volumio sudo[30764]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:33:32 volumio volumio[30590]: info: [1770705212338] CoreMusicLibrary::Adding element Media Servers Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:33:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:33:32 volumio sudo[30777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:33:32 volumio sudo[30777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:32 volumio volumio[30590]: info: UPNP Browser: Client initialized successfully Feb 10 13:33:32 volumio sudo[30777]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:33:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:33:32 volumio sudo[30779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:33:32 volumio systemd[1]: mpd.service: Consumed 7.161s CPU time. Feb 10 13:33:32 volumio sudo[30779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:33:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:33:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:33:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:33:32 volumio volumio[30590]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:33:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:33:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:33:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:33:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:33:32 volumio volumio[30590]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:33:32 volumio volumio[30590]: info: [1770705212730] CoreMusicLibrary::Adding element Last_100 Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:33:32 volumio volumio[30590]: info: [1770705212741] CoreMusicLibrary::Adding element Webradio Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:33:32 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:33:32 volumio volumio[30590]: info: Initializing BBC Radios Feb 10 13:33:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:33:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:33:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 13:33:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:32 volumio go-librespot[30802]: go-librespot daemon starting... Feb 10 13:33:32 volumio go-librespot[30803]: time="2026-02-10T13:33:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:32 volumio go-librespot[30803]: time="2026-02-10T13:33:32+07:00" level=debug msg="app state loaded" Feb 10 13:33:32 volumio go-librespot[30803]: time="2026-02-10T13:33:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:33 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:33:33 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:33 volumio volumio[30590]: info: Creating Spotify config file Feb 10 13:33:33 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:33 volumio sudo[30796]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:33:33 volumio sudo[30796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:33:33 volumio sudo[30796]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:33 volumio go-librespot[30803]: time="2026-02-10T13:33: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:33:33 volumio go-librespot[30803]: time="2026-02-10T13:33:33+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 10 13:33:33 volumio go-librespot[30803]: time="2026-02-10T13:33:33+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 10 13:33:33 volumio go-librespot[30803]: time="2026-02-10T13:33:33+07:00" level=info msg="zeroconf server listening on port 39663" Feb 10 13:33:34 volumio go-librespot[30803]: time="2026-02-10T13:33:34+07:00" level=debug msg="obtained new client token: AAC7XKzHY9xfRoD1NtKPDNqoZO87iox4b5K0Zm7YLj3rdipyySxSnxsFZRNPjSrye7NMn2bUKa+xfSwW7bPOy3h/2TI8TdrYluFmtlbXu8B0sLGzbdwUEjzlE79MpVlhJbz/g7xTSLe6uURakiMsXYNZachbw3ZXWR5XCe1f5j89S0I82P60ciYVeDYzFNCimDbquBhBtVkBd4qYUpbB/K7ncRWz+1zb+VBQsKyi6yRynkH/sZfYZYF3Ag==" Feb 10 13:33:34 volumio go-librespot[30803]: time="2026-02-10T13:33:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:34 volumio volumio[30713]: Starting albumart workers Feb 10 13:33:34 volumio volumio[30714]: Starting albumart workers Feb 10 13:33:34 volumio go-librespot[30803]: time="2026-02-10T13:33:34+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:34 volumio go-librespot[30803]: time="2026-02-10T13:33:34+07:00" level=debug msg="completed challenge" Feb 10 13:33:34 volumio go-librespot[30803]: time="2026-02-10T13:33:34+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 10 13:33:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:34 volumio volumio[30715]: Starting albumart workers Feb 10 13:33:34 volumio volumio[30590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:33:34 volumio volumio[30590]: info: [1770705214474] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:33:34 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:33:34 volumio volumio[30590]: Cannot find translation for source YouTube Music Feb 10 13:33:34 volumio volumio[30590]: info: Volumio Calling Home Feb 10 13:33:34 volumio sudo[30818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:33:34 volumio sudo[30818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:34 volumio sudo[30818]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:35 volumio volumio[30590]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:33:35 volumio volumio[30590]: info: Discovery: Found device Volumio Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::volumioGetState Feb 10 13:33:35 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:35 volumio volumio[30590]: info: MPD Permissions set Feb 10 13:33:35 volumio volumio[30590]: info: MPD Permissions set Feb 10 13:33:35 volumio volumio[30590]: info: Upmpdcli Daemon Started Feb 10 13:33:35 volumio volumio[30590]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:33:35 volumio volumio[30590]: info: Discovery: Found device Volumio Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::volumioGetState Feb 10 13:33:35 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:35 volumio volumio[30590]: info: Volumio called home Feb 10 13:33:35 volumio volumio[30590]: info: Spotify config file written Feb 10 13:33:35 volumio sudo[30826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:33:35 volumio sudo[30826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:35 volumio volumio[30590]: 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 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:35 volumio go-librespot[30828]: go-librespot daemon starting... Feb 10 13:33:36 volumio sudo[30826]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+07:00" level=debug msg="app state loaded" Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:33:36 volumio volumio[30590]: info: No need to fix Spotify hosts Feb 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+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 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+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 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+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 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+07:00" level=info msg="zeroconf server listening on port 34257" Feb 10 13:33:36 volumio go-librespot[30829]: time="2026-02-10T13:33:36+07:00" level=debug msg="obtained new client token: AACH6aEgKZ/JlsWZhAWLExULL2Cg+fnmrTXQMjWIJtVkyBDUaeeK49BS1g6zc6zhbHnK+rrVsBQbMeT4bcWTsbugBPYPakPvjPZGcXFLu+BCNWl+7TSm8AzJPVDAjvKP5yk2Io3okiQWEcB2hJN9PXIkS/wTDcTYsN2LsT56n2tZO1+bF3CJlfapPCKj4kjDCxpv5hI3VYXJ8wPd4S3oOEKnAmYoosUT35fqlSILQuNq4K/uEmDKt5Jdxg==" Feb 10 13:33:37 volumio go-librespot[30829]: time="2026-02-10T13:33:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:37 volumio volumio[30590]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:33:37 volumio volumio[30590]: SPOTIFY: BQA4SyYCFKdakaAaEUmNtQN-rkDHNcIBGzEQE5_glqDnzGDMXq731k9JhVgdF0tq-rmor36DYKSlMYQtrS5ViBKVZUBhCX6NmBuxie-GngNEsdudHiqA_0k-SHNSncj8qiKIC8ez3SpSKzJ-SNucrhXR_X0WSpIWkIsWO469a0USlaTC7wOEXQ3UULarQ8NOnYx4_x2GGo7lDGKCTp-t49ZFR4On8bT-vnjhEI-f-p6QuAH_m8hpVsJIiwS3PYswAWkNbU9ndXpRouR8L9QxQBlLG7XEC4sXfXO8IGYBuyCDxKrcEs8Eg_iT Feb 10 13:33:37 volumio volumio[30590]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:33:37 volumio volumio[30590]: info: New Spotify access token = BQA4SyYCFKdakaAaEUmNtQN-rkDHNcIBGzEQE5_glqDnzGDMXq731k9JhVgdF0tq-rmor36DYKSlMYQtrS5ViBKVZUBhCX6NmBuxie-GngNEsdudHiqA_0k-SHNSncj8qiKIC8ez3SpSKzJ-SNucrhXR_X0WSpIWkIsWO469a0USlaTC7wOEXQ3UULarQ8NOnYx4_x2GGo7lDGKCTp-t49ZFR4On8bT-vnjhEI-f-p6QuAH_m8hpVsJIiwS3PYswAWkNbU9ndXpRouR8L9QxQBlLG7XEC4sXfXO8IGYBuyCDxKrcEs8Eg_iT Feb 10 13:33:37 volumio volumio[30590]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:33:37 volumio go-librespot[30829]: time="2026-02-10T13:33:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:33:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:37 volumio volumio[30590]: info: Starting Shairport Sync Feb 10 13:33:37 volumio volumio[30590]: info: Starting Shairport Sync Feb 10 13:33:37 volumio volumio[30590]: info: Starting Shairport Sync Feb 10 13:33:37 volumio sudo[30865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:33:37 volumio sudo[30865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:37 volumio sudo[30870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:33:37 volumio sudo[30870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:33:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:33:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:33:37 volumio systemd[1]: shairport-sync.service: Consumed 2.210s CPU time. Feb 10 13:33:37 volumio sudo[30867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:33:37 volumio sudo[30867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:33:37 volumio sudo[30865]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:33:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:33:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:33:37 volumio volumio[30590]: info: Shairport-Sync Started Feb 10 13:33:37 volumio volumio[30590]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:33:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:33:37 volumio sudo[30870]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:37 volumio sudo[30867]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:37 volumio volumio[30590]: info: CoreCommandRouter::volumioGetState Feb 10 13:33:37 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:37 volumio volumio[30590]: info: Shairport-Sync Started Feb 10 13:33:37 volumio volumio[30590]: info: Shairport-Sync Started Feb 10 13:33:38 volumio volumio[30590]: 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 10 13:33:38 volumio volumio[30590]: info: Spotify Successfully logged in Feb 10 13:33:38 volumio volumio[30590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:33:38 volumio volumio[30590]: info: [1770705218068] CoreMusicLibrary::Adding element Spotify Feb 10 13:33:38 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:33:38 volumio volumio[30590]: Cannot find translation for source YouTube Music Feb 10 13:33:38 volumio volumio[30590]: Cannot find translation for source Spotify Feb 10 13:33:38 volumio volumio[30590]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:33:38 volumio volumio[30590]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:33:38 volumio volumio[30590]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:33:38 volumio volumio[30590]: info: CoreCommandRouter::volumioGetState Feb 10 13:33:38 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:38 volumio volumio[30590]: info: CoreStateMachine::pushState Feb 10 13:33:38 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:38 volumio volumio[30590]: info: CoreCommandRouter::volumioPushState Feb 10 13:33:40 volumio volumio[30590]: info: go-librespot daemon successfully initialized Feb 10 13:33:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 13:33:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:40 volumio mpd[30816]: 2026-02-10T13:33:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:33:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:40 volumio go-librespot[30906]: go-librespot daemon starting... Feb 10 13:33:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:33:40 volumio sudo[30768]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:40 volumio sudo[30779]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+07:00" level=debug msg="app state loaded" Feb 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:40 volumio volumio[30590]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:33:40 volumio volumio[30590]: assert.ok(self.idling) Feb 10 13:33:40 volumio volumio[30590]: error: The expression evaluated to a falsy value: Feb 10 13:33:40 volumio volumio[30590]: assert.ok(self.idling) Feb 10 13:33:40 volumio volumio[30590]: info: MPD running with PID30816 Feb 10 13:33:40 volumio volumio[30590]: ,establishing connection Feb 10 13:33:40 volumio volumio[30590]: error: updateQueue error: null Feb 10 13:33:40 volumio volumio[30590]: info: Completed starting Core Plugins Feb 10 13:33:40 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:40 volumio volumio[30590]: info: ----- MyVolumio plugins startup ---- Feb 10 13:33:40 volumio volumio[30590]: info: ------------------------------------------- Feb 10 13:33:40 volumio volumio[30590]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:33:40 volumio volumio[30590]: error: updateQueue error: null Feb 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+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 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+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 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+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 10 13:33:40 volumio go-librespot[30909]: time="2026-02-10T13:33:40+07:00" level=info msg="zeroconf server listening on port 36895" Feb 10 13:33:41 volumio go-librespot[30909]: time="2026-02-10T13:33:41+07:00" level=debug msg="obtained new client token: AACCPsIExszbUpUgdLdmgZMnmRjvtt8k3NVMCIgKdAth2d3OUvXMOeXvgXCbcRzJGj/kALUvIBoxHkxOSjGXRtbGPfC5IbUHstlL0rhqKBKxQnb3LwH3maZDfEfgPhCRyOx1XTc4xrCMNmf1nlf+KSxPv2Isutc191RmB4NkUY91RiCgQEYq5ui668oUG0sAwQ1+Hr1G6+YjDnP/jbKdVU4jFuEq26gvMqAoM0BHU+McUZxvspG4TgU=" Feb 10 13:33:41 volumio go-librespot[30909]: time="2026-02-10T13:33:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:41 volumio go-librespot[30909]: time="2026-02-10T13:33:41+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:41 volumio go-librespot[30909]: time="2026-02-10T13:33:41+07:00" level=debug msg="completed challenge" Feb 10 13:33:41 volumio go-librespot[30909]: time="2026-02-10T13:33:41+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 10 13:33:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:43 volumio volumio[30590]: info: Initializing connection to go-librespot Websocket Feb 10 13:33:43 volumio volumio[30590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:33:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 13:33:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:44 volumio go-librespot[30919]: go-librespot daemon starting... Feb 10 13:33:44 volumio go-librespot[30920]: time="2026-02-10T13:33:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:44 volumio go-librespot[30920]: time="2026-02-10T13:33:44+07:00" level=debug msg="app state loaded" Feb 10 13:33:44 volumio go-librespot[30920]: time="2026-02-10T13:33:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+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 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+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 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+07:00" level=info msg="zeroconf server listening on port 38161" Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+07:00" level=debug msg="obtained new client token: AABj/YoKzP0YvJvLZBoXIUSozBC7WBaCyVudNEkwwdO23yMdA3r6TrnBfNx3P6cwrkU7y30T5+TQVZyhlRbNHSjp4C42/zl/bfCflsqrZlQU46ybiRm3WYWNVc4aS+NSFJwZw4LMs5r2Ett3xlajh+QO75925QKNnJ26hzeUcRUjox0NzzUXTLMm0xhjXv4FLXDn0N/PbhsyCVGwjl8QwY78KXZnpb0ID4EL+XgR1+u/093iK8PyiG776g==" Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:45 volumio volumio[30590]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+07:00" level=debug msg="completed challenge" Feb 10 13:33:45 volumio go-librespot[30920]: time="2026-02-10T13:33:45+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 10 13:33:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:46 volumio volumio[30590]: info: Initializing connection to go-librespot Websocket Feb 10 13:33:46 volumio volumio[30590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:33:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 10 13:33:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:48 volumio go-librespot[30928]: go-librespot daemon starting... Feb 10 13:33:48 volumio go-librespot[30929]: time="2026-02-10T13:33:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:48 volumio go-librespot[30929]: time="2026-02-10T13:33:48+07:00" level=debug msg="app state loaded" Feb 10 13:33:48 volumio go-librespot[30929]: time="2026-02-10T13:33:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:49 volumio volumio[30590]: info: Initializing connection to go-librespot Websocket Feb 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+07:00" level=debug msg="new websocket client" Feb 10 13:33:49 volumio volumio[30590]: info: Connection to go-librespot Websocket established Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 13:33:49 volumio volumio[30590]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+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 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+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 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+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 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+07:00" level=info msg="zeroconf server listening on port 33201" Feb 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+07:00" level=debug msg="obtained new client token: AADRqlAu2JRhVIhvUHRLx9qtQi9ednwvB4+MviHSLnbIgOuJnIriPf1urWJAqyU/BLMDgOHFXpEovA9HyrvVP8oaQpYK4Xl6QMa2B+z8B/CzTyXrqgGF99JfCrGEEHpR1RY+n0scL2g2XCnUlid66PaSRIPGTuBdCRPxQF2zBuapXy0/4d0BpClVsIje++bxLomX0BYpJlBQG254uwahkzOmBrRpKx4ghVYSuLaz2ZIG1wdxO8x7IsA2EQ==" Feb 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:49 volumio go-librespot[30929]: time="2026-02-10T13:33:49+07:00" level=debug msg="completed challenge" Feb 10 13:33:50 volumio go-librespot[30929]: time="2026-02-10T13:33: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 10 13:33:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:51 volumio volumio[30590]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 13:33:51 volumio volumio[30590]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 13:33:51 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:51 volumio volumio[30590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:33:51 volumio volumio[30590]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 13:33:51 volumio volumio[30590]: info: MyVolumio login type: Token Feb 10 13:33:51 volumio volumio[30590]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 13:33:51 volumio volumio[30590]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 13:33:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 10 13:33:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:53 volumio volumio[30590]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 13:33:53 volumio volumio[30590]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 13:33:53 volumio volumio[30590]: info: Streaming services startup Feb 10 13:33:53 volumio volumio[30590]: info: Starting Streaming Daemon Feb 10 13:33:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:33:53 volumio go-librespot[30951]: go-librespot daemon starting... Feb 10 13:33:53 volumio sudo[30953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 13:33:53 volumio volumio[30590]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 13:33:53 volumio sudo[30953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+07:00" level=debug msg="app state loaded" Feb 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:33:53 volumio sudo[30953]: pam_unix(sudo:session): session closed for user root Feb 10 13:33:53 volumio volumio[30590]: info: Getting Spotify volume Feb 10 13:33:53 volumio volumio[30590]: info: Connection to go-librespot Websocket closed Feb 10 13:33:53 volumio volumio[30590]: error: Cannot start Volumio Streaming Daemon Feb 10 13:33:53 volumio volumio[30590]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 13:33:53 volumio volumio[30590]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 13:33:53 volumio volumio[30590]: 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 10 13:33:53 volumio volumio[30590]: info: CoreCommandRouter::volumioGetState Feb 10 13:33:53 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:53 volumio volumio[30590]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 13:33:53 volumio volumio[30590]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 13:33:53 volumio volumio[30590]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 13:33:53 volumio volumio[30590]: info: Aligning Spotify Volume to Volumio Volume Feb 10 13:33:53 volumio volumio[30590]: info: CoreCommandRouter::volumioGetState Feb 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+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 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+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 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+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 10 13:33:53 volumio volumio[30590]: info: CorePlayQueue::getTrack 0 Feb 10 13:33:53 volumio volumio[30590]: info: Setting Spotify Volume from Volumio: 100 Feb 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+07:00" level=info msg="zeroconf server listening on port 42151" Feb 10 13:33:53 volumio go-librespot[30954]: time="2026-02-10T13:33:53+07:00" level=debug msg="obtained new client token: AADJXNGI7XG3MuqKvpr8bYEiVoUa4XyRpMJZCfXcx32zcQAu9zscpXnYBxrusyMMn7J77l2mr9vyAE97vU6TU2KYSHHEqTDEsh35frM+QWWMJv0UcAE3Kh/WY1kGbcSbojtrJTQB8MrX3tVfshTxNZvWzKVHR0vJhzxAVMtzwAQNondn1rZr/EGzoU6PUXn/my+VXbR4Kw2O4oLIPnnFKeeDVdrg+wI2OHX0hkGeJ52ktJ1fy9nSuqmd8Q==" Feb 10 13:33:54 volumio go-librespot[30954]: time="2026-02-10T13:33:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:33:54 volumio go-librespot[30954]: time="2026-02-10T13:33:54+07:00" level=debug msg="completed keyexchange" Feb 10 13:33:54 volumio go-librespot[30954]: time="2026-02-10T13:33:54+07:00" level=debug msg="completed challenge" Feb 10 13:33:54 volumio go-librespot[30954]: time="2026-02-10T13:33: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 10 13:33:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:33:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:33:54 volumio volumio[30590]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:33:54 volumio volumio[30590]: Error: socket hang up Feb 10 13:33:54 volumio volumio[30590]: at connResetException (node:internal/errors:720:14) Feb 10 13:33:54 volumio volumio[30590]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 13:33:54 volumio volumio[30590]: at Socket.emit (node:events:526:35) Feb 10 13:33:54 volumio volumio[30590]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 13:33:54 volumio volumio[30590]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 13:33:54 volumio volumio[30590]: code: 'ECONNRESET', Feb 10 13:33:54 volumio volumio[30590]: response: undefined Feb 10 13:33:54 volumio volumio[30590]: } Feb 10 13:33:54 volumio volumio[30590]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:33:55 volumio sudo[30982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:32' Feb 10 13:33:55 volumio sudo[30982]: 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"