Jan 28 08:47:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Jan 28 08:47:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:00 volumio go-librespot[21061]: go-librespot daemon starting... Jan 28 08:47:00 volumio go-librespot[21062]: time="2026-01-28T08:47:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:00 volumio go-librespot[21062]: time="2026-01-28T08:47:00+07:00" level=debug msg="app state loaded" Jan 28 08:47:00 volumio go-librespot[21062]: time="2026-01-28T08:47:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:01 volumio volumio[20972]: info: Loading plugin "ytmusic"... Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+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]" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+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]" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+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]" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+07:00" level=info msg="zeroconf server listening on port 39817" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+07:00" level=debug msg="obtained new client token: AABe7uayoxj4SfNs+KJgWeMv55U95s6fBuW5DgSdRyqLjlBDdAcNLBffbNuwwWfzNSGmTbcvBiLb8PPQFoRHbcbLUCDFlM3yYvqaVoBkESksv/3xxD9ffhOxa333P65CHIIzLbV87M/2niQcWFmmFVeMQYl5+n9Kglpeq4NMIWRJKNnfSfBmT1sZN/E74RIl4/1ER8gB3GKCpjFFgDnGLHjBHm0QlW2hfj5XQ0eEDShQmz1WvNyCed3dTcA=" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+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" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:01 volumio go-librespot[21062]: time="2026-01-28T08:47:01+07:00" level=debug msg="completed challenge" Jan 28 08:47:01 volumio volumio-remote-updater[628]: [2026-01-28 08:47:01] [connect] Successful connection Jan 28 08:47:02 volumio go-librespot[21062]: time="2026-01-28T08:47: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 " Jan 28 08:47:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "outputs"... Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "albumart"... Jan 28 08:47:02 volumio volumio[20972]: info: Plugin example_plugin is not enabled Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "inputs"... Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "updater_comm"... Jan 28 08:47:02 volumio volumio[20972]: info: Plugin mpdemulation is not enabled Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "rest_api"... Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "websocket"... Jan 28 08:47:02 volumio volumio[20972]: info: Starting Socket.io Server version 1.7.4 Jan 28 08:47:02 volumio volumio[20972]: info: Loading plugin "RoonBridge"... Jan 28 08:47:02 volumio volumio[20972]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 08:47:02 volumio volumio[20972]: info: Loading i18n strings for locale en Jan 28 08:47:02 volumio volumio[20972]: Updating browse sources language Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::initPlayerControls Jan 28 08:47:03 volumio volumio[21083]: Forking 3 albumart workers Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:47:03 volumio volumio[20972]: Express server listening on port 3000 Jan 28 08:47:03 volumio volumio[20972]: [Metrics] WebUI: 16s 22.19ms Jan 28 08:47:03 volumio volumio[20972]: info: CoreStateMachine::resetVolumioState Jan 28 08:47:03 volumio volumio[20972]: info: CoreStateMachine::getcurrentVolume Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:47:03 volumio sudo[21128]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 08:47:03 volumio sudo[21128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:03 volumio volumio[20972]: info: Volumio Network Manager: Network status updated: 1 Jan 28 08:47:03 volumio sudo[21128]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:03 volumio sudo[21130]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 08:47:03 volumio sudo[21130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:03 volumio sudo[21130]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:03 volumio volumio[20972]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:47:03 volumio volumio[20972]: info: CoreStateMachine::pushState Jan 28 08:47:03 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:03 volumio volumio[20972]: info: CoreStateMachine::updateTrackBlock Jan 28 08:47:03 volumio volumio[20972]: info: CorePlayQueue::getTrackBlock Jan 28 08:47:03 volumio volumio[20972]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:47:03 volumio volumio-remote-updater[628]: [2026-01-28 08:47:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769564821 101 Jan 28 08:47:03 volumio volumio[20972]: 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 Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:04 volumio volumio[20972]: info: Reloading queue from file Jan 28 08:47:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:04 volumio volumio[20972]: info: CoreStateMachine::setRepeat null single undefined Jan 28 08:47:04 volumio volumio[20972]: info: CoreStateMachine::pushState Jan 28 08:47:04 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:04 volumio volumio[20972]: info: CoreStateMachine::setRandom null Jan 28 08:47:04 volumio volumio[20972]: info: CoreStateMachine::pushState Jan 28 08:47:04 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:04 volumio volumio[20972]: info: Setting Device type: Raspberry PI Jan 28 08:47:04 volumio volumio[20972]: info: Completed loading Core Plugins Jan 28 08:47:04 volumio volumio[20972]: info: Preparing to generate the ALSA configuration file Jan 28 08:47:04 volumio volumio[20972]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:47:04 volumio volumio[20972]: info: CoreStateMachine::pushState Jan 28 08:47:04 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:04 volumio volumio[20972]: info: Asound.conf file unchanged, so no further update is needed Jan 28 08:47:04 volumio volumio[20972]: info: Output device has changed, restarting MPD Jan 28 08:47:04 volumio volumio[20972]: info: Output device has changed, restarting Shairport Sync Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:04 volumio sudo[21146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 08:47:04 volumio sudo[21148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 08:47:04 volumio sudo[21148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:04 volumio sudo[21148]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:04 volumio sudo[21146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:04 volumio sudo[21150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 08:47:04 volumio sudo[21150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:04 volumio volumio[20972]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:47:04 volumio volumio[20972]: info: ___________ START PLUGINS ___________ Jan 28 08:47:04 volumio sudo[21146]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 08:47:04 volumio volumio[20972]: info: ControllerMpd::onStart: Initializing MPD Jan 28 08:47:04 volumio volumio[20972]: info: Creating MPD Configuration file Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:04 volumio volumio[20972]: info: [1769564824720] CoreMusicLibrary::Adding element Media Servers Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:04 volumio volumio[20972]: info: UPNP Browser: Client initialized successfully Jan 28 08:47:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 08:47:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 08:47:04 volumio systemd[1]: mpd.service: Consumed 7.047s CPU time. Jan 28 08:47:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 08:47:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 08:47:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 08:47:04 volumio sudo[21159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 08:47:04 volumio sudo[21159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:04 volumio sudo[21159]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:04 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:04 volumio sudo[21161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 08:47:04 volumio sudo[21161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 08:47:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 08:47:05 volumio volumio[20972]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Jan 28 08:47:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:05 volumio volumio[20972]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:05 volumio volumio[20972]: info: [1769564825136] CoreMusicLibrary::Adding element Last_100 Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:05 volumio volumio[20972]: info: [1769564825166] CoreMusicLibrary::Adding element Webradio Jan 28 08:47:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:05 volumio go-librespot[21174]: go-librespot daemon starting... Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:05 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 08:47:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 08:47:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 08:47:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 08:47:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+07:00" level=debug msg="app state loaded" Jan 28 08:47:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:47:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 08:47:05 volumio volumio[20972]: info: Initializing BBC Radios Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:05 volumio volumio[20972]: info: Creating Spotify config file Jan 28 08:47:05 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:05 volumio sudo[21182]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 08:47:05 volumio sudo[21182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 08:47:05 volumio sudo[21182]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+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]" Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+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]" Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+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]" Jan 28 08:47:05 volumio go-librespot[21175]: time="2026-01-28T08:47:05+07:00" level=info msg="zeroconf server listening on port 45803" Jan 28 08:47:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:06 volumio go-librespot[21175]: time="2026-01-28T08:47:06+07:00" level=debug msg="obtained new client token: AADtbhpOEGjEeYAybUEEPMN0a6STU/9tP9XGU4yJw452ONE2ECYPK7r5mMgkRglna9lVko8PNo+m/SlwFu5da8+oROLOTLLOA0P83Z3zxvdbX/2VMMXIh5UY2m+nQYMpNRhNCi3ktg6K6N5OhJGpBYADjNvKDSq30UMu5+cxwlv/cFcOH17bnOF84osaYmXkFkYQr+Slr7rUBKhTayX6cJr+1NjyQzwyoElsGadP+jw572E5xHk+Ha9k" Jan 28 08:47:06 volumio go-librespot[21175]: time="2026-01-28T08:47:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:06 volumio go-librespot[21175]: time="2026-01-28T08:47:06+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:06 volumio go-librespot[21175]: time="2026-01-28T08:47:06+07:00" level=debug msg="completed challenge" Jan 28 08:47:06 volumio go-librespot[21175]: time="2026-01-28T08:47:06+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 " Jan 28 08:47:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:06 volumio volumio[21095]: Starting albumart workers Jan 28 08:47:06 volumio volumio[21097]: Starting albumart workers Jan 28 08:47:07 volumio volumio[20972]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:07 volumio volumio[20972]: info: [1769564827003] CoreMusicLibrary::Adding element YouTube Music Jan 28 08:47:07 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:07 volumio volumio[20972]: Cannot find translation for source YouTube Music Jan 28 08:47:07 volumio volumio[20972]: info: Volumio Calling Home Jan 28 08:47:07 volumio volumio[21098]: Starting albumart workers Jan 28 08:47:07 volumio sudo[21201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 08:47:07 volumio sudo[21201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:07 volumio sudo[21201]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:07 volumio volumio[20972]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 08:47:07 volumio volumio[20972]: info: Discovery: Found device Volumio Jan 28 08:47:07 volumio volumio[20972]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:07 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:07 volumio volumio[20972]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 08:47:07 volumio volumio[20972]: info: Discovery: Found device Volumio Jan 28 08:47:07 volumio volumio[20972]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:07 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:07 volumio volumio[20972]: info: MPD Permissions set Jan 28 08:47:07 volumio volumio[20972]: info: MPD Permissions set Jan 28 08:47:07 volumio volumio[20972]: info: Upmpdcli Daemon Started Jan 28 08:47:07 volumio volumio[20972]: info: Spotify config file written Jan 28 08:47:07 volumio volumio[20972]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 08:47:08 volumio sudo[21208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 08:47:08 volumio sudo[21208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:08 volumio go-librespot[21215]: go-librespot daemon starting... Jan 28 08:47:08 volumio sudo[21208]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:08 volumio volumio[20972]: info: No need to fix Spotify hosts Jan 28 08:47:08 volumio go-librespot[21218]: time="2026-01-28T08:47:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:08 volumio go-librespot[21218]: time="2026-01-28T08:47:08+07:00" level=debug msg="app state loaded" Jan 28 08:47:08 volumio go-librespot[21218]: time="2026-01-28T08:47:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+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]" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+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]" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+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]" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+07:00" level=info msg="zeroconf server listening on port 43349" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+07:00" level=debug msg="obtained new client token: AACGUR3xnubNaZxW4em0iJMPg+lJvIo3n9qa1t4ImPFSoXnjxYnybxONdittmVGxjNrE4zUUadgv1doH4wYCBiqnZcqs4SK1oc+QQpUkFmedSf7HFQKSHSR9rNl5i/w6SJ0ol3cq5+M2RyxoG4Ek3BMNZB0spuI/mKcN8udGDU5RmLVINvSWZg3AvDZw9RsepRRc+FjMLKcdVMtTmTWSxNsHRphu2xzJERd2U5csQgj2IU0nSuCJtPN6ttU=" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+07:00" level=debug msg="completed challenge" Jan 28 08:47:09 volumio go-librespot[21218]: time="2026-01-28T08:47:09+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 " Jan 28 08:47:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:09 volumio volumio[20972]: info: Volumio called home Jan 28 08:47:09 volumio volumio[20972]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 08:47:09 volumio volumio[20972]: SPOTIFY: BQD3yomWKCU6hf1FbFtegMhsGfpI-p2Q2CMlJw1f5b4apMWn5shcTPSihktBOFT3Mx0DRLv376S1fvCEejAijF1jMbBSRA3MtORsrv24RTnJBIj8s7QKuvY2EY0OQGseTEA4onBmvM2IbXjVo1HMqVI3cwQyFIOcJdYAgvdnlUFcTFMkS5gRw2TdG0rmd03GnltO2CnUqhMEoqn4wWfj9UD-w2g9DbFXh5pslYZX8z9HK9kVq3B0jj6NeKQ2ERb2o96pDUPVozW66B2J6TVeibh5EXd7NAxHxOxjkW8fAfb4Od4g7J-CAhaC Jan 28 08:47:09 volumio volumio[20972]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 08:47:09 volumio volumio[20972]: info: New Spotify access token = BQD3yomWKCU6hf1FbFtegMhsGfpI-p2Q2CMlJw1f5b4apMWn5shcTPSihktBOFT3Mx0DRLv376S1fvCEejAijF1jMbBSRA3MtORsrv24RTnJBIj8s7QKuvY2EY0OQGseTEA4onBmvM2IbXjVo1HMqVI3cwQyFIOcJdYAgvdnlUFcTFMkS5gRw2TdG0rmd03GnltO2CnUqhMEoqn4wWfj9UD-w2g9DbFXh5pslYZX8z9HK9kVq3B0jj6NeKQ2ERb2o96pDUPVozW66B2J6TVeibh5EXd7NAxHxOxjkW8fAfb4Od4g7J-CAhaC Jan 28 08:47:09 volumio volumio[20972]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 08:47:09 volumio volumio[20972]: info: Starting Shairport Sync Jan 28 08:47:09 volumio volumio[20972]: info: Starting Shairport Sync Jan 28 08:47:09 volumio volumio[20972]: info: Starting Shairport Sync Jan 28 08:47:09 volumio sudo[21249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:47:09 volumio sudo[21249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:09 volumio sudo[21251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:47:09 volumio sudo[21251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 08:47:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 08:47:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:47:09 volumio systemd[1]: shairport-sync.service: Consumed 2.236s CPU time. Jan 28 08:47:09 volumio sudo[21253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:47:09 volumio sudo[21253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:47:10 volumio sudo[21249]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 08:47:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 08:47:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:47:10 volumio volumio[20972]: info: Shairport-Sync Started Jan 28 08:47:10 volumio volumio[20972]: Error adding Membership: Error: addMembership EINVAL Jan 28 08:47:10 volumio volumio[20972]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:10 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:47:10 volumio sudo[21253]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:10 volumio sudo[21251]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:10 volumio volumio[20972]: info: Shairport-Sync Started Jan 28 08:47:10 volumio volumio[20972]: info: Shairport-Sync Started Jan 28 08:47:10 volumio volumio[20972]: 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"} Jan 28 08:47:10 volumio volumio[20972]: info: Spotify Successfully logged in Jan 28 08:47:10 volumio volumio[20972]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:10 volumio volumio[20972]: info: [1769564830516] CoreMusicLibrary::Adding element Spotify Jan 28 08:47:10 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:10 volumio volumio[20972]: Cannot find translation for source YouTube Music Jan 28 08:47:10 volumio volumio[20972]: Cannot find translation for source Spotify Jan 28 08:47:11 volumio volumio[20972]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 08:47:11 volumio volumio[20972]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:47:11 volumio volumio[20972]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:47:11 volumio volumio[20972]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:11 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:11 volumio volumio[20972]: info: CoreStateMachine::pushState Jan 28 08:47:11 volumio volumio[20972]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:11 volumio volumio[20972]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:12 volumio volumio[20972]: info: go-librespot daemon successfully initialized Jan 28 08:47:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Jan 28 08:47:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:12 volumio go-librespot[21289]: go-librespot daemon starting... Jan 28 08:47:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:12 volumio go-librespot[21290]: time="2026-01-28T08:47:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:12 volumio go-librespot[21290]: time="2026-01-28T08:47:12+07:00" level=debug msg="app state loaded" Jan 28 08:47:12 volumio go-librespot[21290]: time="2026-01-28T08:47:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:12 volumio mpd[21199]: 2026-01-28T08:47:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 08:47:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 08:47:12 volumio sudo[21161]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:12 volumio sudo[21150]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:13 volumio volumio[20972]: error: MPD error: The expression evaluated to a falsy value: Jan 28 08:47:13 volumio volumio[20972]: assert.ok(self.idling) Jan 28 08:47:13 volumio volumio[20972]: error: The expression evaluated to a falsy value: Jan 28 08:47:13 volumio volumio[20972]: assert.ok(self.idling) Jan 28 08:47:13 volumio volumio[20972]: info: MPD running with PID21199 Jan 28 08:47:13 volumio volumio[20972]: ,establishing connection Jan 28 08:47:13 volumio volumio[20972]: error: updateQueue error: null Jan 28 08:47:13 volumio volumio[20972]: info: Completed starting Core Plugins Jan 28 08:47:13 volumio volumio[20972]: info: ------------------------------------------- Jan 28 08:47:13 volumio volumio[20972]: info: ----- MyVolumio plugins startup ---- Jan 28 08:47:13 volumio volumio[20972]: info: ------------------------------------------- Jan 28 08:47:13 volumio volumio[20972]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 08:47:13 volumio volumio[20972]: error: updateQueue error: null Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+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]" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+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]" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+07:00" level=info msg="zeroconf server listening on port 35883" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+07:00" level=debug msg="obtained new client token: AAB22diWzHg8sOt7X1i05gubhOvyxPuM/Yt09iF2bcaeByloQJXWWtjga++CCBGtFVKBqdqUU28r+e1VbQTKFtAh51PdnL93YapdLo9/hmvpZn98x4SJ46OGm/6xTSC2t56GOaiKCcX0IcmAohAXw/xDvORK9bYoC8n2Nj6NAs3NnjhBSuamTw1GAJ63ha+XuFgKcQGeghhyLCTcLbrvJV/LmOXcCkJ+BAj58/WJ5T2r87/+Jn75t+zOttk=" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:13 volumio go-librespot[21290]: time="2026-01-28T08:47:13+07:00" level=debug msg="completed challenge" Jan 28 08:47:14 volumio go-librespot[21290]: time="2026-01-28T08:47: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 " Jan 28 08:47:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:15 volumio volumio[20972]: info: Initializing connection to go-librespot Websocket Jan 28 08:47:15 volumio volumio[20972]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:47:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Jan 28 08:47:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:17 volumio go-librespot[21301]: go-librespot daemon starting... Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+07:00" level=debug msg="app state loaded" Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+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]" Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+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]" Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+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]" Jan 28 08:47:17 volumio go-librespot[21302]: time="2026-01-28T08:47:17+07:00" level=info msg="zeroconf server listening on port 41497" Jan 28 08:47:18 volumio volumio[20972]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 08:47:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:18 volumio go-librespot[21302]: time="2026-01-28T08:47:18+07:00" level=debug msg="obtained new client token: AABVC0DbByuWLhHOHNakzMx4I6NZJr07O1+Gdn2AL21iz6fYVx58DMDKMS1l8D7XV4X2e+cVjIr32kkaKkCthl0Bt5fSizz1Rdc+Feq5afr5CTFQOHMX7zcygSuHq5THjQdlpRinwYFB9v05zH/JD5GkF7a6GpCe5hrdFFu7L50wON3gCOIyVsNJnl+zGzYAhqqVRCFhpwQ1it800VQspsr2Mf6a8OyjzKCfSLgR/NOJoT6grZZVrd0F" Jan 28 08:47:18 volumio go-librespot[21302]: time="2026-01-28T08:47:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:18 volumio go-librespot[21302]: time="2026-01-28T08:47:18+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:18 volumio go-librespot[21302]: time="2026-01-28T08:47:18+07:00" level=debug msg="completed challenge" Jan 28 08:47:18 volumio go-librespot[21302]: time="2026-01-28T08:47:18+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 " Jan 28 08:47:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:18 volumio volumio[20972]: info: Initializing connection to go-librespot Websocket Jan 28 08:47:18 volumio volumio[20972]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:47:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Jan 28 08:47:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:21 volumio go-librespot[21310]: go-librespot daemon starting... Jan 28 08:47:21 volumio go-librespot[21311]: time="2026-01-28T08:47:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:21 volumio go-librespot[21311]: time="2026-01-28T08:47:21+07:00" level=debug msg="app state loaded" Jan 28 08:47:21 volumio go-librespot[21311]: time="2026-01-28T08:47:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:21 volumio volumio[20972]: info: Initializing connection to go-librespot Websocket Jan 28 08:47:21 volumio go-librespot[21311]: time="2026-01-28T08:47:21+07:00" level=debug msg="new websocket client" Jan 28 08:47:21 volumio volumio[20972]: info: Connection to go-librespot Websocket established Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 08:47:21 volumio volumio[20972]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 08:47:21 volumio volumio[20972]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 08:47:21 volumio volumio[20972]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 08:47:21 volumio volumio[20972]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 08:47:21 volumio volumio[20972]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 08:47:21 volumio volumio[20972]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 08:47:21 volumio volumio[20972]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 08:47:22 volumio volumio[20972]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 08:47:22 volumio volumio[20972]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 08:47:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47: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]" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47: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]" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47: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]" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47:22+07:00" level=info msg="zeroconf server listening on port 39581" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47:22+07:00" level=debug msg="obtained new client token: AAAJHMNcSs+MkaaMCbUM/3lOgXDmxAT6WN7rqo9T8UAPI2JeMdVK9iP56BxUVUOyKAp9msgCzZeEpzLlm3mukN34NQmvrWPMx0/kFyLTYhGdduCSfNX1JWDYDfqbKd8Oywt2QwIMGA4giHOiow64HakoBc6TfF0/kpys59FZbx2uUzQlVjM+qgZ92nIeE0PbVU100OmWR6c5HDm0B48//7Oc5IBzJbOJxhWDm/BUPyLVZrOHCGvFzOb6IGI=" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47:22+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47:22+07:00" level=debug msg="completed challenge" Jan 28 08:47:22 volumio go-librespot[21311]: time="2026-01-28T08:47: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 " Jan 28 08:47:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:23 volumio volumio[20972]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 08:47:23 volumio volumio[20972]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 08:47:23 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:23 volumio volumio[20972]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:23 volumio volumio[20972]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 08:47:23 volumio volumio[20972]: info: MyVolumio login type: Token Jan 28 08:47:24 volumio volumio[20972]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 08:47:24 volumio volumio[20972]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 08:47:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:25 volumio volumio[20972]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 08:47:25 volumio volumio[20972]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 08:47:25 volumio volumio[20972]: info: Streaming services startup Jan 28 08:47:25 volumio volumio[20972]: info: Starting Streaming Daemon Jan 28 08:47:25 volumio sudo[21333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 08:47:25 volumio sudo[21333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:25 volumio volumio[20972]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 08:47:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Jan 28 08:47:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:25 volumio volumio[20972]: info: Getting Spotify volume Jan 28 08:47:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:25 volumio go-librespot[21339]: go-librespot daemon starting... Jan 28 08:47:25 volumio volumio[20972]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 08:47:25 volumio sudo[21333]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:25 volumio volumio[20972]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:47:25 volumio volumio[20972]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 08:47:25 volumio volumio[20972]: errno: -111, Jan 28 08:47:25 volumio volumio[20972]: code: 'ECONNREFUSED', Jan 28 08:47:25 volumio volumio[20972]: syscall: 'connect', Jan 28 08:47:25 volumio volumio[20972]: address: '127.0.0.1', Jan 28 08:47:25 volumio volumio[20972]: port: 9879, Jan 28 08:47:25 volumio volumio[20972]: response: undefined Jan 28 08:47:25 volumio volumio[20972]: } Jan 28 08:47:25 volumio volumio[20972]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 08:47:25 volumio go-librespot[21340]: time="2026-01-28T08:47:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:25 volumio go-librespot[21340]: time="2026-01-28T08:47:25+07:00" level=debug msg="app state loaded" Jan 28 08:47:25 volumio go-librespot[21340]: time="2026-01-28T08:47:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+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]" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+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]" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+07:00" level=info msg="zeroconf server listening on port 34937" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+07:00" level=debug msg="obtained new client token: AABndsuGQmS2SMqZ7/Tyw547D+n+cdvBMeKmrDPDKHL20qxaK4UreHJtIPSGi7SBZC2tl2Nj6A5X1XtWidoQRkgmFXbCz4kJFt8cAvUAUg3kjOYSH6ySU1ACuumjntr+ciM16GNCPJjQU3OQ+Zomtq18otUAX2RtxAiQ7ls7uTh4wWvSaKDnxqS/2tNXe8EMNqz+HiE9XNFlfvED8zl3sBuZB04SuL+5UDeVn2B41csB263i3HTuy39iJzg=" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+07:00" level=debug msg="completed challenge" Jan 28 08:47:26 volumio go-librespot[21340]: time="2026-01-28T08:47:26+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 " Jan 28 08:47:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:27 volumio sudo[21361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 08:46' Jan 28 08:47:27 volumio sudo[21361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:27 volumio sudo[21361]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:27 volumio volumio-remote-updater[628]: [2026-01-28 08:47:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 08:47:27 volumio volumio-remote-updater[628]: [2026-01-28 08:47:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 08:47:27 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:27 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 08:47:27 volumio systemd[1]: volumio.service: Consumed 58.572s CPU time. Jan 28 08:47:27 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 08:47:27 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 08:47:27 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9856. Jan 28 08:47:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 08:47:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 08:47:28 volumio systemd[1]: volumio.service: Consumed 58.572s CPU time. Jan 28 08:47:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 08:47:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 08:47:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Jan 28 08:47:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:30 volumio go-librespot[21388]: go-librespot daemon starting... Jan 28 08:47:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+07:00" level=debug msg="app state loaded" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47: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-gew1.spotify.com:80]" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+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]" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+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]" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+07:00" level=info msg="zeroconf server listening on port 45295" Jan 28 08:47:30 volumio go-librespot[21389]: time="2026-01-28T08:47:30+07:00" level=debug msg="obtained new client token: AADz2vEzNRWRMzCgs/vEtaY0S+pKv2SiiVCx5OLfGkRquE6C1JQFVycLF7kBSylZmmM63rR1kW2dQS01sDCbiSdArsSAhrwSzWm1vSSml49dSdYt1BjGuXMupqjySCW9jMQWxXJT16MWTKnsZSG8382sz1XYDzI0JVc/R3QhWyin7Z0kxur7hkFuiXBOsKfEc7ECxreJIYYMONRjvMoytUoGry8Pm16hRme2zx6B5wUkjzb1jZidZl7/mtw=" Jan 28 08:47:31 volumio go-librespot[21389]: time="2026-01-28T08:47:31+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" Jan 28 08:47:31 volumio go-librespot[21389]: time="2026-01-28T08:47:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 08:47:31 volumio go-librespot[21389]: time="2026-01-28T08:47:31+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:31 volumio go-librespot[21389]: time="2026-01-28T08:47:31+07:00" level=debug msg="completed challenge" Jan 28 08:47:31 volumio go-librespot[21389]: time="2026-01-28T08:47:31+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 " Jan 28 08:47:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:31 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:31 volumio volumio[21373]: info: ----- Volumio3 ---- Jan 28 08:47:31 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:31 volumio volumio[21373]: info: ----- System startup ---- Jan 28 08:47:31 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:32 volumio volumio-remote-updater[628]: [2026-01-28 08:47:32] [connect] Successful connection Jan 28 08:47:32 volumio volumio[21373]: info: MYVOLUMIO Environment detected Jan 28 08:47:33 volumio volumio[21373]: info: Plugin folders cleanup Jan 28 08:47:33 volumio volumio[21373]: info: Scanning into folder /volumio/app/plugins/ Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category audio_interface Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category miscellanea Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category music_service Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category plugins.json Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category system_controller Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category user_interface Jan 28 08:47:33 volumio volumio[21373]: info: Scanning into folder /data/plugins/ Jan 28 08:47:33 volumio volumio[21373]: info: Scanning category music_service Jan 28 08:47:33 volumio volumio[21373]: info: Plugin folders cleanup completed Jan 28 08:47:33 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:33 volumio volumio[21373]: info: ----- Core plugins startup ---- Jan 28 08:47:33 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:33 volumio volumio[21373]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 08:47:33 volumio volumio[21373]: info: Adding plugin upnp to MyMusic Plugins Jan 28 08:47:33 volumio volumio[21373]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 08:47:33 volumio volumio[21373]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 08:47:33 volumio volumio[21373]: info: Loading plugins from folder /data/plugins/ Jan 28 08:47:33 volumio volumio[21373]: info: Loading plugin "system"... Jan 28 08:47:33 volumio volumio[21373]: info: Loading plugin "appearance"... Jan 28 08:47:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Jan 28 08:47:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:34 volumio go-librespot[21408]: go-librespot daemon starting... Jan 28 08:47:34 volumio go-librespot[21409]: time="2026-01-28T08:47:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:34 volumio go-librespot[21409]: time="2026-01-28T08:47:34+07:00" level=debug msg="app state loaded" Jan 28 08:47:34 volumio go-librespot[21409]: time="2026-01-28T08:47:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "network"... Jan 28 08:47:35 volumio volumio[21373]: info: Refreshing Cached IP Addresses Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47: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-gew4.spotify.com:80]" Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+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]" Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+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]" Jan 28 08:47:35 volumio sudo[21418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 08:47:35 volumio sudo[21418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "services"... Jan 28 08:47:35 volumio sudo[21418]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:35 volumio sudo[21420]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 08:47:35 volumio sudo[21420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "alsa_controller"... Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+07:00" level=info msg="zeroconf server listening on port 33871" Jan 28 08:47:35 volumio sudo[21420]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:35 volumio sudo[21424]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 08:47:35 volumio sudo[21424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:35 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "wizard"... Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "networkfs"... Jan 28 08:47:35 volumio volumio[21373]: info: Starting Udev Watcher for removable devices Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+07:00" level=debug msg="obtained new client token: AACFo7K39pYVI8pS48Z5OrCWff/LKw2w9x7q38Lj05M7c8oW+S5dn0u6Zf9bCn5V+6xxDYtnOLZXoS4vC6eGY9a1nzE8SwLvAP83F1sDD50eErDyPT3Z0MKXA6hslKuac/6aPoXav1q2PClQGxWsMff5gqoaFGTivaJWs9f95b+PCDCmLKDDpoUytUURYA+KrgOXFNp+YPAMiW85fxbKS8iElz9u1YC5dRyolzjH5PgntejnEQ7XkcIs5vs=" Jan 28 08:47:35 volumio volumio[21373]: info: Ignoring mount for partition: boot Jan 28 08:47:35 volumio volumio[21373]: info: Ignoring mount for partition: volumio Jan 28 08:47:35 volumio volumio[21373]: info: Ignoring mount for partition: volumio_data Jan 28 08:47:35 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "volumio_command_line_client"... Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "upnp"... Jan 28 08:47:35 volumio volumio[21373]: info: [1769564855559] Starting Upmpd Daemon Jan 28 08:47:35 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "my_music"... Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+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" Jan 28 08:47:35 volumio volumio[21373]: info: Loading plugin "mpd"... Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47:35+07:00" level=debug msg="completed challenge" Jan 28 08:47:35 volumio go-librespot[21409]: time="2026-01-28T08:47: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 " Jan 28 08:47:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:36 volumio volumio[21373]: info: Loading plugin "upnp_browser"... Jan 28 08:47:38 volumio sudo[21424]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Jan 28 08:47:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:39 volumio go-librespot[21451]: go-librespot daemon starting... Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+07:00" level=debug msg="app state loaded" Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:39 volumio volumio[21373]: info: Starting UPNP Browser Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "alarm-clock"... Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "airplay_emulation"... Jan 28 08:47:39 volumio volumio[21373]: info: Starting Shairport Sync Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "last_100"... Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "webradio"... Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+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]" Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+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]" Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+07:00" level=info msg="zeroconf server listening on port 44035" Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "i2s_dacs"... Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "volumiodiscovery"... Jan 28 08:47:39 volumio volumio[21373]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 08:47:39 volumio volumio[21373]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:47:39 volumio volumio[21373]: *** WARNING *** For more information see Jan 28 08:47:39 volumio volumio[21373]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 08:47:39 volumio volumio[21373]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:47:39 volumio volumio[21373]: *** WARNING *** For more information see Jan 28 08:47:39 volumio node[21373]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 08:47:39 volumio node[21373]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:47:39 volumio node[21373]: *** WARNING *** For more information see Jan 28 08:47:39 volumio node[21373]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 08:47:39 volumio node[21373]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:47:39 volumio node[21373]: *** WARNING *** For more information see Jan 28 08:47:39 volumio volumio[21373]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 08:47:39 volumio volumio[21373]: info: Discovery: Started advertising with name: Volumio Jan 28 08:47:39 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 08:47:39 volumio volumio[21373]: info: Loading plugin "spop"... Jan 28 08:47:39 volumio go-librespot[21452]: time="2026-01-28T08:47:39+07:00" level=debug msg="obtained new client token: AABprMAs67GpGC/RlT0KO9ImUPnOeuOYe98fTzXLlu2c2lQMMsExH9EVAyuDdSlZT/Eq2V9JC/AgWf7w8XZCCPvyYpauDSveHYFsTXOcENRrqthjiNvJLqqLqvjxbqWGLxEUZcQ1XkTjMAAos5MdW4iAw4KuxvF1zAWt28rvREMQATYURzA72HBbl8fyUSP9ZDSN0MoD9QtJ2dyE8l91VOT6XTbyPq66iqanTca+ZKIQcm1myc5Bg/dVQWw=" Jan 28 08:47:40 volumio go-librespot[21452]: time="2026-01-28T08:47:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:40 volumio go-librespot[21452]: time="2026-01-28T08:47:40+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:40 volumio go-librespot[21452]: time="2026-01-28T08:47:40+07:00" level=debug msg="completed challenge" Jan 28 08:47:40 volumio go-librespot[21452]: time="2026-01-28T08:47:40+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 " Jan 28 08:47:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:41 volumio volumio[21373]: info: Loading plugin "ytcr"... Jan 28 08:47:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Jan 28 08:47:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:43 volumio go-librespot[21461]: go-librespot daemon starting... Jan 28 08:47:43 volumio go-librespot[21462]: time="2026-01-28T08:47:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:43 volumio go-librespot[21462]: time="2026-01-28T08:47:43+07:00" level=debug msg="app state loaded" Jan 28 08:47:43 volumio go-librespot[21462]: time="2026-01-28T08:47:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+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]" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+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]" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+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]" Jan 28 08:47:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+07:00" level=info msg="zeroconf server listening on port 34907" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+07:00" level=debug msg="obtained new client token: AADlhcmTMpuFWplGxoNhCQ/CfQxB8S+xpx460f6UucsWqwbuSp+EeotZNxtMcsvNIuzrCZco8MD1S4OwXvAUkILPqgL+xgjXVOOYc8V3+S3IFQ49tWpM8CsSqt9Dgi89QEpgAZH239ZSD3JFaqbzZIy4IvVmUPsBm8miPDSqQn0I9KxNaGdkz7Ps1cN/WQ3PaSP5R9X+3lOvafvvYZpKwtUJpdDW7VcpzVCN+HYWq5XjYZfOnZUss3J7+4c=" Jan 28 08:47:44 volumio volumio[21373]: info: Loading plugin "ytmusic"... Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47:44+07:00" level=debug msg="completed challenge" Jan 28 08:47:44 volumio go-librespot[21462]: time="2026-01-28T08:47: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 " Jan 28 08:47:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:45 volumio volumio-remote-updater[628]: [2026-01-28 08:47:45] [connect] Successful connection Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "outputs"... Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "albumart"... Jan 28 08:47:45 volumio volumio[21373]: info: Plugin example_plugin is not enabled Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "inputs"... Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "updater_comm"... Jan 28 08:47:45 volumio volumio[21373]: info: Plugin mpdemulation is not enabled Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "rest_api"... Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "websocket"... Jan 28 08:47:45 volumio volumio[21373]: info: Starting Socket.io Server version 1.7.4 Jan 28 08:47:45 volumio volumio[21373]: info: Loading plugin "RoonBridge"... Jan 28 08:47:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:46 volumio volumio[21373]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 08:47:46 volumio volumio[21373]: info: Loading i18n strings for locale en Jan 28 08:47:46 volumio volumio[21373]: Updating browse sources language Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:46 volumio volumio[21483]: Forking 3 albumart workers Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::initPlayerControls Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:47:46 volumio volumio[21373]: Express server listening on port 3000 Jan 28 08:47:46 volumio volumio[21373]: [Metrics] WebUI: 16s 71.90ms Jan 28 08:47:46 volumio volumio[21373]: info: CoreStateMachine::resetVolumioState Jan 28 08:47:46 volumio volumio[21373]: info: CoreStateMachine::getcurrentVolume Jan 28 08:47:46 volumio volumio[21373]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:47:46 volumio sudo[21527]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 08:47:46 volumio sudo[21527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:46 volumio sudo[21531]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 08:47:46 volumio sudo[21531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:46 volumio sudo[21527]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:47 volumio sudo[21531]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:47 volumio volumio[21373]: info: Volumio Network Manager: Network status updated: 1 Jan 28 08:47:47 volumio volumio[21373]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::pushState Jan 28 08:47:47 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::updateTrackBlock Jan 28 08:47:47 volumio volumio[21373]: info: CorePlayQueue::getTrackBlock Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:47:47 volumio volumio-remote-updater[628]: [2026-01-28 08:47:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769564865 101 Jan 28 08:47:47 volumio volumio[21373]: 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 Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:47 volumio volumio[21373]: info: Reloading queue from file Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::setRepeat null single undefined Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::pushState Jan 28 08:47:47 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::setRandom null Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::pushState Jan 28 08:47:47 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:47 volumio volumio[21373]: info: Setting Device type: Raspberry PI Jan 28 08:47:47 volumio volumio[21373]: info: Completed loading Core Plugins Jan 28 08:47:47 volumio volumio[21373]: info: Preparing to generate the ALSA configuration file Jan 28 08:47:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Jan 28 08:47:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:47 volumio go-librespot[21544]: go-librespot daemon starting... Jan 28 08:47:47 volumio volumio[21373]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:47:47 volumio volumio[21373]: info: CoreStateMachine::pushState Jan 28 08:47:47 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:47 volumio volumio[21373]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:47 volumio go-librespot[21546]: time="2026-01-28T08:47:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:47 volumio go-librespot[21546]: time="2026-01-28T08:47:47+07:00" level=debug msg="app state loaded" Jan 28 08:47:47 volumio go-librespot[21546]: time="2026-01-28T08:47:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:47 volumio volumio[21373]: info: Asound.conf file unchanged, so no further update is needed Jan 28 08:47:47 volumio volumio[21373]: info: Output device has changed, restarting MPD Jan 28 08:47:48 volumio volumio[21373]: info: Output device has changed, restarting Shairport Sync Jan 28 08:47:48 volumio sudo[21554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 08:47:48 volumio sudo[21554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:48 volumio sudo[21556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 08:47:48 volumio sudo[21556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:48 volumio sudo[21556]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:48 volumio volumio[21373]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:47:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:48 volumio volumio[21373]: info: ___________ START PLUGINS ___________ Jan 28 08:47:48 volumio sudo[21554]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:48 volumio sudo[21558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 08:47:48 volumio sudo[21558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:48 volumio volumio[21373]: info: ControllerMpd::onStart: Initializing MPD Jan 28 08:47:48 volumio volumio[21373]: info: Creating MPD Configuration file Jan 28 08:47:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:47:48 volumio sudo[21567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:48 volumio volumio[21373]: info: [1769564868310] CoreMusicLibrary::Adding element Media Servers Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:48 volumio sudo[21567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:48 volumio sudo[21567]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:48 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 08:47:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 08:47:48 volumio systemd[1]: mpd.service: Consumed 7.284s CPU time. Jan 28 08:47:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 08:47:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 08:47:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 08:47:48 volumio volumio[21373]: info: UPNP Browser: Client initialized successfully Jan 28 08:47:48 volumio sudo[21569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 08:47:48 volumio sudo[21569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 08:47:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:48 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 08:47:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 08:47:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 08:47:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 08:47:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 08:47:48 volumio volumio[21373]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 08:47:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 08:47:48 volumio go-librespot[21546]: time="2026-01-28T08:47: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 08:47:48 volumio go-librespot[21546]: time="2026-01-28T08:47:48+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]" Jan 28 08:47:48 volumio go-librespot[21546]: time="2026-01-28T08:47:48+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]" Jan 28 08:47:48 volumio volumio[21373]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:48 volumio volumio[21373]: info: [1769564868728] CoreMusicLibrary::Adding element Last_100 Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:48 volumio go-librespot[21546]: time="2026-01-28T08:47:48+07:00" level=info msg="zeroconf server listening on port 37913" Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:48 volumio volumio[21373]: info: [1769564868776] CoreMusicLibrary::Adding element Webradio Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:47:48 volumio volumio[21373]: info: Initializing BBC Radios Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:48 volumio go-librespot[21546]: time="2026-01-28T08:47:48+07:00" level=debug msg="obtained new client token: AABqmR5Fs3dbKta5mjrgeqICRtJsOvr9o/92UI1pIbjrFNox1LSM3ODWLLBaNYTDWL7QF4QN/Yx7/xFPiHthl5j2NgYRzGsS4KshqcO0UNlD/b7a2hu3iW5xno6ebqKXtKzCYCZ+41ufwCt30ndKj1z5GYkGEO1bJVPPBqe+P8WCmh+DWj6A4XKsLc0vvveerqgXnl4YDT6+vKFVAimCxwt3Xr5l7mvh2CX8MOVx1mYfllLR9VKwsXtWBvE=" Jan 28 08:47:48 volumio volumio[21373]: info: Creating Spotify config file Jan 28 08:47:48 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:49 volumio go-librespot[21546]: time="2026-01-28T08:47:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:49 volumio sudo[21583]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 08:47:49 volumio sudo[21583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 08:47:49 volumio sudo[21583]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:49 volumio go-librespot[21546]: time="2026-01-28T08:47:49+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:49 volumio go-librespot[21546]: time="2026-01-28T08:47:49+07:00" level=debug msg="completed challenge" Jan 28 08:47:49 volumio go-librespot[21546]: time="2026-01-28T08:47:49+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 " Jan 28 08:47:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:49 volumio volumio[21496]: Starting albumart workers Jan 28 08:47:50 volumio volumio[21495]: Starting albumart workers Jan 28 08:47:50 volumio volumio[21373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:50 volumio volumio[21373]: info: [1769564870119] CoreMusicLibrary::Adding element YouTube Music Jan 28 08:47:50 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:50 volumio volumio[21373]: Cannot find translation for source YouTube Music Jan 28 08:47:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:50 volumio volumio[21494]: Starting albumart workers Jan 28 08:47:50 volumio volumio[21373]: info: Volumio Calling Home Jan 28 08:47:50 volumio sudo[21600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 08:47:50 volumio sudo[21600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:50 volumio sudo[21600]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:51 volumio volumio[21373]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 08:47:51 volumio volumio[21373]: info: Discovery: Found device Volumio Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:51 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:51 volumio volumio[21373]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 08:47:51 volumio volumio[21373]: info: Discovery: Found device Volumio Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:51 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:51 volumio volumio[21373]: info: MPD Permissions set Jan 28 08:47:51 volumio volumio[21373]: info: MPD Permissions set Jan 28 08:47:51 volumio volumio[21373]: info: Upmpdcli Daemon Started Jan 28 08:47:51 volumio volumio[21373]: info: Spotify config file written Jan 28 08:47:51 volumio sudo[21606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 08:47:51 volumio sudo[21606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:51 volumio volumio[21373]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio go-librespot[21609]: go-librespot daemon starting... Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio sudo[21606]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:47:51 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:47:51 volumio go-librespot[21614]: time="2026-01-28T08:47:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:51 volumio go-librespot[21614]: time="2026-01-28T08:47:51+07:00" level=debug msg="app state loaded" Jan 28 08:47:51 volumio go-librespot[21614]: time="2026-01-28T08:47:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:51 volumio volumio[21373]: info: No need to fix Spotify hosts Jan 28 08:47:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:52 volumio go-librespot[21614]: time="2026-01-28T08:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 08:47:52 volumio go-librespot[21614]: time="2026-01-28T08:47:52+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]" Jan 28 08:47:52 volumio go-librespot[21614]: time="2026-01-28T08:47:52+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]" Jan 28 08:47:52 volumio go-librespot[21614]: time="2026-01-28T08:47:52+07:00" level=info msg="zeroconf server listening on port 36131" Jan 28 08:47:52 volumio volumio[21373]: info: Volumio called home Jan 28 08:47:52 volumio go-librespot[21614]: time="2026-01-28T08:47:52+07:00" level=debug msg="obtained new client token: AABaLVvjfVfE4pZqp9u8t4Ur+R2tOKSFdMAQms6wXwVI6nTKo2kJee+lIzPaUfFtFttaclCCR7895oWunBnzzBKgmDrhm3JhmOXAOHDtaS91pErmZSJTYkJ/ngN48F/fsOc6zG88MC/GMwELSiGYU/IlRTR7M5FyJlhNOXoyuEFmjOakRpFSzb6L35a+pFdpURQWSVjB3N9rZwiwhGX4sMijNhok7TvSGANyKPgEE/S5cNp1ZWEmXJe5+Eg=" Jan 28 08:47:52 volumio volumio[21373]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 08:47:52 volumio volumio[21373]: SPOTIFY: BQA2ioHqnnW3ZU50EjTJSB0R15XRKRt8usZoo5uFUal_vH0GL245Vmu2uYPbmzDWFbM4K25xkWwrOXfoI2Vd_Gaq4NKCDhrIGuALWgGGboyz5z8udd53aCYVXiUA_vIudtS3Vnc7_mCY8BBP7638rVvCJ9BSI3ZS2RiYpiqwoEuIcPi6s_Dld4WiW_rrQhynjo8_bAoTw9e2D8pctn6CEcocPCMVALwCzOptyfQsSWomoPoo9iCpNmfHvMUOPmerp9qD3HxSM46IGQvv9JHd0h6O0FWtA1lOFCL90y_C6mzrPOdrpFEUAtNI Jan 28 08:47:52 volumio volumio[21373]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 08:47:52 volumio volumio[21373]: info: New Spotify access token = BQA2ioHqnnW3ZU50EjTJSB0R15XRKRt8usZoo5uFUal_vH0GL245Vmu2uYPbmzDWFbM4K25xkWwrOXfoI2Vd_Gaq4NKCDhrIGuALWgGGboyz5z8udd53aCYVXiUA_vIudtS3Vnc7_mCY8BBP7638rVvCJ9BSI3ZS2RiYpiqwoEuIcPi6s_Dld4WiW_rrQhynjo8_bAoTw9e2D8pctn6CEcocPCMVALwCzOptyfQsSWomoPoo9iCpNmfHvMUOPmerp9qD3HxSM46IGQvv9JHd0h6O0FWtA1lOFCL90y_C6mzrPOdrpFEUAtNI Jan 28 08:47:52 volumio go-librespot[21614]: time="2026-01-28T08:47:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:52 volumio volumio[21373]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 08:47:53 volumio go-librespot[21614]: time="2026-01-28T08:47:53+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:53 volumio go-librespot[21614]: time="2026-01-28T08:47:53+07:00" level=debug msg="completed challenge" Jan 28 08:47:53 volumio volumio[21373]: info: Starting Shairport Sync Jan 28 08:47:53 volumio volumio[21373]: info: Starting Shairport Sync Jan 28 08:47:53 volumio volumio[21373]: info: Starting Shairport Sync Jan 28 08:47:53 volumio go-librespot[21614]: time="2026-01-28T08:47:53+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 " Jan 28 08:47:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:53 volumio sudo[21645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:47:53 volumio sudo[21645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:53 volumio sudo[21647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:47:53 volumio sudo[21647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:53 volumio sudo[21649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:47:53 volumio sudo[21649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:47:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 08:47:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 08:47:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:47:53 volumio systemd[1]: shairport-sync.service: Consumed 2.322s CPU time. Jan 28 08:47:53 volumio volumio[21373]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:53 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:53 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:47:53 volumio sudo[21645]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:53 volumio sudo[21649]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:53 volumio sudo[21647]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:53 volumio volumio[21373]: info: Shairport-Sync Started Jan 28 08:47:53 volumio volumio[21373]: Error adding Membership: Error: addMembership EINVAL Jan 28 08:47:53 volumio volumio[21373]: info: Shairport-Sync Started Jan 28 08:47:53 volumio volumio[21373]: info: Shairport-Sync Started Jan 28 08:47:53 volumio volumio[21373]: 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"} Jan 28 08:47:53 volumio volumio[21373]: info: Spotify Successfully logged in Jan 28 08:47:53 volumio volumio[21373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:47:53 volumio volumio[21373]: info: [1769564873838] CoreMusicLibrary::Adding element Spotify Jan 28 08:47:53 volumio volumio[21373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:47:53 volumio volumio[21373]: Cannot find translation for source YouTube Music Jan 28 08:47:53 volumio volumio[21373]: Cannot find translation for source Spotify Jan 28 08:47:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:54 volumio volumio[21373]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 08:47:54 volumio volumio[21373]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:47:54 volumio volumio[21373]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:47:54 volumio volumio[21373]: info: CoreCommandRouter::volumioGetState Jan 28 08:47:54 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:54 volumio volumio[21373]: info: CoreStateMachine::pushState Jan 28 08:47:54 volumio volumio[21373]: info: CorePlayQueue::getTrack 0 Jan 28 08:47:54 volumio volumio[21373]: info: CoreCommandRouter::volumioPushState Jan 28 08:47:55 volumio volumio[21373]: info: go-librespot daemon successfully initialized Jan 28 08:47:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Jan 28 08:47:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:47:56 volumio go-librespot[21686]: go-librespot daemon starting... Jan 28 08:47:56 volumio mpd[21598]: 2026-01-28T08:47:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 08:47:56 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+07:00" level=debug msg="app state loaded" Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:47:56 volumio sudo[21558]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:56 volumio sudo[21569]: pam_unix(sudo:session): session closed for user root Jan 28 08:47:56 volumio volumio[21373]: error: MPD error: The expression evaluated to a falsy value: Jan 28 08:47:56 volumio volumio[21373]: assert.ok(self.idling) Jan 28 08:47:56 volumio volumio[21373]: error: The expression evaluated to a falsy value: Jan 28 08:47:56 volumio volumio[21373]: assert.ok(self.idling) Jan 28 08:47:56 volumio volumio[21373]: info: MPD running with PID21598 Jan 28 08:47:56 volumio volumio[21373]: ,establishing connection Jan 28 08:47:56 volumio volumio[21373]: error: updateQueue error: null Jan 28 08:47:56 volumio volumio[21373]: info: Completed starting Core Plugins Jan 28 08:47:56 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:56 volumio volumio[21373]: info: ----- MyVolumio plugins startup ---- Jan 28 08:47:56 volumio volumio[21373]: info: ------------------------------------------- Jan 28 08:47:56 volumio volumio[21373]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 08:47:56 volumio volumio[21373]: error: updateQueue error: null Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+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]" Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+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]" Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+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]" Jan 28 08:47:56 volumio go-librespot[21687]: time="2026-01-28T08:47:56+07:00" level=info msg="zeroconf server listening on port 34797" Jan 28 08:47:57 volumio go-librespot[21687]: time="2026-01-28T08:47:57+07:00" level=debug msg="obtained new client token: AABIzsg+MmBdFXw98DPIFIi6gtGLPfgcYHIcgceyVSM7gk0drhyVpq/DwnA5Tbb6w4/7flgUPyPv5ojJvpcpW74rGVBjewsMzPp7bPVba4bmIh5AxfElA0s8RbvWM3vzJFaEn60xpnF5+OlPBPBbe4xmKIYCQ3wBX+K801bk3QTkMcj8RPMei4Xo9AZZQMi5iJj5EMnxGOvclNr0Io5jAJ0s00SAauroF7jPT4fjUC28I8h4ZFrqOdGb" Jan 28 08:47:57 volumio go-librespot[21687]: time="2026-01-28T08:47:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:47:57 volumio go-librespot[21687]: time="2026-01-28T08:47:57+07:00" level=debug msg="completed keyexchange" Jan 28 08:47:57 volumio go-librespot[21687]: time="2026-01-28T08:47:57+07:00" level=debug msg="completed challenge" Jan 28 08:47:57 volumio go-librespot[21687]: time="2026-01-28T08:47:57+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 " Jan 28 08:47:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:47:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:47:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:47:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:47:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:47:58 volumio volumio[21373]: info: Initializing connection to go-librespot Websocket Jan 28 08:47:58 volumio volumio[21373]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:48:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Jan 28 08:48:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:00 volumio go-librespot[21699]: go-librespot daemon starting... Jan 28 08:48:00 volumio go-librespot[21700]: time="2026-01-28T08:48:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:00 volumio go-librespot[21700]: time="2026-01-28T08:48:00+07:00" level=debug msg="app state loaded" Jan 28 08:48:00 volumio go-librespot[21700]: time="2026-01-28T08:48:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+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]" Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+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]" Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+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]" Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+07:00" level=info msg="zeroconf server listening on port 43559" Jan 28 08:48:01 volumio volumio[21373]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+07:00" level=debug msg="obtained new client token: AABTZ7CtQ/HJyxOFnKyNEB5gTPrU/aM6xIe0x9krf7UXGB77BiNl7UKQ97wFJ7POvNqjHYrEsoNdsoXGKNE5eL0YrzmwbPiaQKmawHg0kfE3EsM9gAlEDg9E+otTF0K5W2zRtjz3m1z2cEwCK+MpaEEa9cHudh1GK+oh0CuxcC9GJQwNs6ycAvjyeua4rvlKdGEyWJqc87cSZNzKKNKF9wxS9knZjNvTSVirQ0POZwwt/I8Ecft+B9vs0Pg=" Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:01 volumio volumio[21373]: info: Initializing connection to go-librespot Websocket Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+07:00" level=debug msg="new websocket client" Jan 28 08:48:01 volumio volumio[21373]: info: Connection to go-librespot Websocket established Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:01 volumio go-librespot[21700]: time="2026-01-28T08:48:01+07:00" level=debug msg="completed challenge" Jan 28 08:48:02 volumio go-librespot[21700]: time="2026-01-28T08:48: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 " Jan 28 08:48:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:02 volumio volumio[21373]: info: Connection to go-librespot Websocket closed Jan 28 08:48:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:04 volumio volumio[21373]: info: Getting Spotify volume Jan 28 08:48:04 volumio volumio[21373]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 08:48:04 volumio volumio[21373]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:48:04 volumio volumio[21373]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 08:48:04 volumio volumio[21373]: errno: -111, Jan 28 08:48:04 volumio volumio[21373]: code: 'ECONNREFUSED', Jan 28 08:48:04 volumio volumio[21373]: syscall: 'connect', Jan 28 08:48:04 volumio volumio[21373]: address: '127.0.0.1', Jan 28 08:48:04 volumio volumio[21373]: port: 9879, Jan 28 08:48:04 volumio volumio[21373]: response: undefined Jan 28 08:48:04 volumio volumio[21373]: } Jan 28 08:48:05 volumio volumio[21373]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 08:48:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Jan 28 08:48:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:05 volumio go-librespot[21720]: go-librespot daemon starting... Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+07:00" level=debug msg="app state loaded" Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+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]" Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+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]" Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+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]" Jan 28 08:48:05 volumio go-librespot[21721]: time="2026-01-28T08:48:05+07:00" level=info msg="zeroconf server listening on port 37931" Jan 28 08:48:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:06 volumio go-librespot[21721]: time="2026-01-28T08:48:06+07:00" level=debug msg="obtained new client token: AAD1njHt7/KnzadhIJN3kjqYVvzboLwE5jF9ZDb6abqM9HTvmCGbWFEWUfzgpufKGPHJ0xBbJAeSdpShKBSCdO5gV55ynbWKiBmERahHSGyfwdvDzhDR14OuX0u+fZjr9skBs/PDcxfDiFPwUAh6Mi/AKGEEDD8RI0NjNyDi7+Zggf9DQ4Ioude/Uz2P0CZtugGPkjbtfX3bs+JDhIAgtnhSVHjPuYgVrVoQWxJSTW7rnJbGg8/pXZwY" Jan 28 08:48:06 volumio go-librespot[21721]: time="2026-01-28T08:48:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:06 volumio go-librespot[21721]: time="2026-01-28T08:48:06+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:06 volumio go-librespot[21721]: time="2026-01-28T08:48:06+07:00" level=debug msg="completed challenge" Jan 28 08:48:06 volumio sudo[21744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 08:47' Jan 28 08:48:06 volumio sudo[21744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:06 volumio go-librespot[21721]: time="2026-01-28T08:48:06+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 " Jan 28 08:48:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:06 volumio sudo[21744]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:06 volumio volumio-remote-updater[628]: [2026-01-28 08:48:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 08:48:06 volumio volumio-remote-updater[628]: [2026-01-28 08:48:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 08:48:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 08:48:06 volumio systemd[1]: volumio.service: Consumed 52.774s CPU time. Jan 28 08:48:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 08:48:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 08:48:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9857. Jan 28 08:48:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 08:48:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 08:48:07 volumio systemd[1]: volumio.service: Consumed 52.774s CPU time. Jan 28 08:48:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 08:48:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 08:48:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Jan 28 08:48:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:09 volumio go-librespot[21772]: go-librespot daemon starting... Jan 28 08:48:09 volumio go-librespot[21773]: time="2026-01-28T08:48:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:09 volumio go-librespot[21773]: time="2026-01-28T08:48:09+07:00" level=debug msg="app state loaded" Jan 28 08:48:09 volumio go-librespot[21773]: time="2026-01-28T08:48:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+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]" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+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]" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+07:00" level=info msg="zeroconf server listening on port 35857" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+07:00" level=debug msg="obtained new client token: AACdRK4VTAjHgMU66sTaOzXshtmNlOsxtZjxsOnnrORetPMSVAVN36qlP0oHmLJ+zvL7P4wqyHqglqoWkxrQ9GbGbuwuC0hveMtioAmA9aRRnx/Gf2mRdlUXnLdG8rFS26wbqfrjDUJKQnpNTlLBs//4lSt5jtrBui+N6vQMpnzeo8jkz36FVU+EpAaPlYRVfGxbBC/5Npd3rDP70lf5CCcg9BEW2W+tZOKLOeJRo7PwxiMKIcWneuUX1oI=" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+07:00" level=debug msg="completed challenge" Jan 28 08:48:10 volumio go-librespot[21773]: time="2026-01-28T08:48:10+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 " Jan 28 08:48:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:10 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:10 volumio volumio[21756]: info: ----- Volumio3 ---- Jan 28 08:48:11 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:11 volumio volumio[21756]: info: ----- System startup ---- Jan 28 08:48:11 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:11 volumio volumio-remote-updater[628]: [2026-01-28 08:48:11] [connect] Successful connection Jan 28 08:48:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:12 volumio volumio[21756]: info: MYVOLUMIO Environment detected Jan 28 08:48:12 volumio volumio[21756]: info: Plugin folders cleanup Jan 28 08:48:12 volumio volumio[21756]: info: Scanning into folder /volumio/app/plugins/ Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category audio_interface Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category miscellanea Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category music_service Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category plugins.json Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category system_controller Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category user_interface Jan 28 08:48:12 volumio volumio[21756]: info: Scanning into folder /data/plugins/ Jan 28 08:48:12 volumio volumio[21756]: info: Scanning category music_service Jan 28 08:48:12 volumio volumio[21756]: info: Plugin folders cleanup completed Jan 28 08:48:12 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:12 volumio volumio[21756]: info: ----- Core plugins startup ---- Jan 28 08:48:12 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:12 volumio volumio[21756]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 08:48:12 volumio volumio[21756]: info: Adding plugin upnp to MyMusic Plugins Jan 28 08:48:12 volumio volumio[21756]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 08:48:12 volumio volumio[21756]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 08:48:12 volumio volumio[21756]: info: Loading plugins from folder /data/plugins/ Jan 28 08:48:12 volumio volumio[21756]: info: Loading plugin "system"... Jan 28 08:48:12 volumio volumio[21756]: info: Loading plugin "appearance"... Jan 28 08:48:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Jan 28 08:48:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:14 volumio go-librespot[21792]: go-librespot daemon starting... Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+07:00" level=debug msg="app state loaded" Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "network"... Jan 28 08:48:14 volumio volumio[21756]: info: Refreshing Cached IP Addresses Jan 28 08:48:14 volumio sudo[21801]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 08:48:14 volumio sudo[21801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:14 volumio sudo[21803]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 08:48:14 volumio sudo[21801]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:14 volumio sudo[21803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "services"... Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "alsa_controller"... Jan 28 08:48:14 volumio sudo[21803]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:14 volumio sudo[21811]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 08:48:14 volumio sudo[21811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+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]" Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+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]" Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+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]" Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+07:00" level=info msg="zeroconf server listening on port 35359" Jan 28 08:48:14 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "wizard"... Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "networkfs"... Jan 28 08:48:14 volumio volumio[21756]: info: Starting Udev Watcher for removable devices Jan 28 08:48:14 volumio volumio[21756]: info: Ignoring mount for partition: boot Jan 28 08:48:14 volumio volumio[21756]: info: Ignoring mount for partition: volumio Jan 28 08:48:14 volumio volumio[21756]: info: Ignoring mount for partition: volumio_data Jan 28 08:48:14 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "volumio_command_line_client"... Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "upnp"... Jan 28 08:48:14 volumio volumio[21756]: info: [1769564894919] Starting Upmpd Daemon Jan 28 08:48:14 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "my_music"... Jan 28 08:48:14 volumio volumio[21756]: info: Loading plugin "mpd"... Jan 28 08:48:14 volumio go-librespot[21793]: time="2026-01-28T08:48:14+07:00" level=debug msg="obtained new client token: AAAQhl2EgVYUGYRmMpxoecvJfS624pwNZkXG9B+m8xnaUaHZ2lqKvcKRCJHl7o/bMCTjd2pAdkJ4HIjzkAenf1sGBwFKdGSh0j0JSfrcok6fpBxP0Nsx8VrqffZi6ThUi5pbBPnEw54bvt+823cunU89PMaj+hnYqWdtee/XNyS78Y4mEtJWr1DdcWA/KB6Ww8YT1hj0VxXLLEcc01YV/jJnVDu7b3I0LLQQbRxZhGFhVT788Mao/zbTIyk=" Jan 28 08:48:15 volumio go-librespot[21793]: time="2026-01-28T08:48:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:15 volumio go-librespot[21793]: time="2026-01-28T08:48:15+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:15 volumio go-librespot[21793]: time="2026-01-28T08:48:15+07:00" level=debug msg="completed challenge" Jan 28 08:48:15 volumio go-librespot[21793]: time="2026-01-28T08:48: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 " Jan 28 08:48:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:15 volumio volumio[21756]: info: Loading plugin "upnp_browser"... Jan 28 08:48:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:17 volumio sudo[21811]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Jan 28 08:48:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:18 volumio volumio[21756]: info: Starting UPNP Browser Jan 28 08:48:18 volumio volumio[21756]: info: Loading plugin "alarm-clock"... Jan 28 08:48:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:18 volumio go-librespot[21834]: go-librespot daemon starting... Jan 28 08:48:18 volumio go-librespot[21835]: time="2026-01-28T08:48:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:18 volumio go-librespot[21835]: time="2026-01-28T08:48:18+07:00" level=debug msg="app state loaded" Jan 28 08:48:18 volumio go-librespot[21835]: time="2026-01-28T08:48:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:18 volumio volumio[21756]: info: Loading plugin "airplay_emulation"... Jan 28 08:48:18 volumio volumio[21756]: info: Starting Shairport Sync Jan 28 08:48:18 volumio volumio[21756]: info: Loading plugin "last_100"... Jan 28 08:48:18 volumio volumio[21756]: info: Loading plugin "webradio"... Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+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]" Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+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]" Jan 28 08:48:19 volumio volumio[21756]: info: Loading plugin "i2s_dacs"... Jan 28 08:48:19 volumio volumio[21756]: info: Loading plugin "volumiodiscovery"... Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+07:00" level=info msg="zeroconf server listening on port 34971" Jan 28 08:48:19 volumio volumio[21756]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 08:48:19 volumio volumio[21756]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:48:19 volumio volumio[21756]: *** WARNING *** For more information see Jan 28 08:48:19 volumio volumio[21756]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 08:48:19 volumio volumio[21756]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:48:19 volumio volumio[21756]: *** WARNING *** For more information see Jan 28 08:48:19 volumio node[21756]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 08:48:19 volumio node[21756]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:48:19 volumio node[21756]: *** WARNING *** For more information see Jan 28 08:48:19 volumio node[21756]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 08:48:19 volumio node[21756]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 08:48:19 volumio node[21756]: *** WARNING *** For more information see Jan 28 08:48:19 volumio volumio[21756]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 08:48:19 volumio volumio[21756]: info: Discovery: Started advertising with name: Volumio Jan 28 08:48:19 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 08:48:19 volumio volumio[21756]: info: Loading plugin "spop"... Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+07:00" level=debug msg="obtained new client token: AADB3+NcljKiWhs4/dHqeG3kS2JmLdKykQ7TAkqUA+6Kx06ekjQaLZ/+6gv1IkVoZFWpcNkR6hgiY1EsM0ArIUzif8B8VDVQb/k06jVmpxco1WWuZ9fhQzYP4uR6wEv9m/08tPMC90jab0Vaxf8lDrEwNToVXle55sLWBn4Y4AvbtXyxoKG8/cd400picY3b3UbYxek7Y/7pIXhO11DEmrAWW5EuduiKQrOO2X6T6fH1IutAfR4LeS0xhwM=" Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+07:00" level=debug msg="completed challenge" Jan 28 08:48:19 volumio go-librespot[21835]: time="2026-01-28T08:48:19+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 " Jan 28 08:48:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:21 volumio volumio[21756]: info: Loading plugin "ytcr"... Jan 28 08:48:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Jan 28 08:48:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:22 volumio go-librespot[21844]: go-librespot daemon starting... Jan 28 08:48:22 volumio go-librespot[21845]: time="2026-01-28T08:48:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:22 volumio go-librespot[21845]: time="2026-01-28T08:48:22+07:00" level=debug msg="app state loaded" Jan 28 08:48:22 volumio go-librespot[21845]: time="2026-01-28T08:48:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+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]" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+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]" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+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]" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+07:00" level=info msg="zeroconf server listening on port 33311" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+07:00" level=debug msg="obtained new client token: AAD+1ebRwtemCJhYUvA2C8ytMAgRnuSeYfADUfH42dPX4vPokPAG3v/GleAfnTq6Sdcid4UQ5jWPjWZhLwp9oVMWNzoA0YlvqZc/TEdkN8mVSfn2J8mVYvIvZpmX+kSPCuQw6gN4RSrLg0Glgd/mkMXQEYp5D7T61IYwwkZTeO7Iokh6//53Kp9H4KoXds91blrW9UwcTABSsWkrTvuueYSlTSnL8jKAGMadxB3R8lszIaR5RvM/CZcfO7w=" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+07:00" level=debug msg="completed challenge" Jan 28 08:48:23 volumio volumio[21756]: info: Loading plugin "ytmusic"... Jan 28 08:48:23 volumio go-librespot[21845]: time="2026-01-28T08:48:23+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 " Jan 28 08:48:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:24 volumio volumio-remote-updater[628]: [2026-01-28 08:48:24] [connect] Successful connection Jan 28 08:48:24 volumio volumio[21756]: info: Loading plugin "outputs"... Jan 28 08:48:24 volumio volumio[21756]: info: Loading plugin "albumart"... Jan 28 08:48:24 volumio volumio[21756]: info: Plugin example_plugin is not enabled Jan 28 08:48:24 volumio volumio[21756]: info: Loading plugin "inputs"... Jan 28 08:48:24 volumio volumio[21756]: info: Loading plugin "updater_comm"... Jan 28 08:48:25 volumio volumio[21756]: info: Plugin mpdemulation is not enabled Jan 28 08:48:25 volumio volumio[21756]: info: Loading plugin "rest_api"... Jan 28 08:48:25 volumio volumio[21756]: info: Loading plugin "websocket"... Jan 28 08:48:25 volumio volumio[21756]: info: Starting Socket.io Server version 1.7.4 Jan 28 08:48:25 volumio volumio[21756]: info: Loading plugin "RoonBridge"... Jan 28 08:48:25 volumio volumio[21756]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 08:48:25 volumio volumio[21756]: info: Loading i18n strings for locale en Jan 28 08:48:25 volumio volumio[21756]: Updating browse sources language Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:48:25 volumio volumio[21866]: Forking 3 albumart workers Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::initPlayerControls Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:25 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:48:26 volumio volumio[21756]: Express server listening on port 3000 Jan 28 08:48:26 volumio volumio[21756]: [Metrics] WebUI: 15s 993.41ms Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::resetVolumioState Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::getcurrentVolume Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:48:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:26 volumio sudo[21908]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 08:48:26 volumio sudo[21908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:26 volumio volumio[21756]: info: Volumio Network Manager: Network status updated: 1 Jan 28 08:48:26 volumio sudo[21908]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:26 volumio sudo[21910]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 08:48:26 volumio sudo[21910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:26 volumio sudo[21910]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:26 volumio volumio[21756]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::pushState Jan 28 08:48:26 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::volumioPushState Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::updateTrackBlock Jan 28 08:48:26 volumio volumio[21756]: info: CorePlayQueue::getTrackBlock Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:48:26 volumio volumio-remote-updater[628]: [2026-01-28 08:48:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769564904 101 Jan 28 08:48:26 volumio volumio[21756]: 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 Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:26 volumio volumio[21756]: info: Reloading queue from file Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::setRepeat null single undefined Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::pushState Jan 28 08:48:26 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::volumioPushState Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::setRandom null Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::pushState Jan 28 08:48:26 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::volumioPushState Jan 28 08:48:26 volumio volumio[21756]: info: Setting Device type: Raspberry PI Jan 28 08:48:26 volumio volumio[21756]: info: Completed loading Core Plugins Jan 28 08:48:26 volumio volumio[21756]: info: Preparing to generate the ALSA configuration file Jan 28 08:48:26 volumio volumio[21756]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:48:26 volumio volumio[21756]: info: CoreStateMachine::pushState Jan 28 08:48:26 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:26 volumio volumio[21756]: info: CoreCommandRouter::volumioPushState Jan 28 08:48:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Jan 28 08:48:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:27 volumio volumio[21756]: info: Asound.conf file unchanged, so no further update is needed Jan 28 08:48:27 volumio volumio[21756]: info: Output device has changed, restarting MPD Jan 28 08:48:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:27 volumio go-librespot[21926]: go-librespot daemon starting... Jan 28 08:48:27 volumio sudo[21928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 08:48:27 volumio sudo[21928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+07:00" level=debug msg="app state loaded" Jan 28 08:48:27 volumio volumio[21756]: info: Output device has changed, restarting Shairport Sync Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:27 volumio sudo[21935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 08:48:27 volumio sudo[21935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:27 volumio sudo[21935]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:27 volumio sudo[21928]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:27 volumio sudo[21938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 08:48:27 volumio sudo[21938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:27 volumio volumio[21756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:48:27 volumio volumio[21756]: info: ___________ START PLUGINS ___________ Jan 28 08:48:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 08:48:27 volumio volumio[21756]: info: ControllerMpd::onStart: Initializing MPD Jan 28 08:48:27 volumio volumio[21756]: info: Creating MPD Configuration file Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 08:48:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 08:48:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 08:48:27 volumio systemd[1]: mpd.service: Consumed 7.292s CPU time. Jan 28 08:48:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 08:48:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 08:48:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:48:27 volumio volumio[21756]: info: [1769564907535] CoreMusicLibrary::Adding element Media Servers Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:48:27 volumio sudo[21947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 08:48:27 volumio sudo[21947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:27 volumio sudo[21947]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 08:48:27 volumio sudo[21949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 08:48:27 volumio sudo[21949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 08:48:27 volumio volumio[21756]: info: UPNP Browser: Client initialized successfully Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 08:48:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 08:48:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 08:48:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 08:48:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 08:48:27 volumio volumio[21756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+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]" Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+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]" Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+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]" Jan 28 08:48:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 08:48:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 08:48:27 volumio go-librespot[21929]: time="2026-01-28T08:48:27+07:00" level=info msg="zeroconf server listening on port 42447" Jan 28 08:48:27 volumio volumio[21756]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:48:27 volumio volumio[21756]: info: [1769564907955] CoreMusicLibrary::Adding element Last_100 Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:48:27 volumio volumio[21756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:48:28 volumio volumio[21756]: info: [1769564908005] CoreMusicLibrary::Adding element Webradio Jan 28 08:48:28 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:48:28 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:48:28 volumio volumio[21756]: info: Initializing BBC Radios Jan 28 08:48:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:28 volumio go-librespot[21929]: time="2026-01-28T08:48:28+07:00" level=debug msg="obtained new client token: AACA1QfKgqsStk2eRvIjqJvAALFtgL1+JmT4lxRg5Q6cAH1MtxmYlVBxCETKkSNvxX9ZmEdRV2sG6eqikAEb8t7jG7PdGCfA1fiu+IU2bmAgUAfaPxv+hLmwbtOvjsl8Lhy6clo9qR52PNoU2ULf82YfQtXGUmRR6aW/+S5wsyFCmmWg4sJeKL3DINKF8Qh9fn1oQqW7LPAaCAsy3Ln6aRrdTmvnmPna0HaOWok/CBwxS4DN6psyGEhX" Jan 28 08:48:28 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 08:48:28 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:28 volumio go-librespot[21929]: time="2026-01-28T08:48:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:28 volumio volumio[21756]: info: Creating Spotify config file Jan 28 08:48:28 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:28 volumio sudo[21964]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 08:48:28 volumio sudo[21964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 08:48:28 volumio go-librespot[21929]: time="2026-01-28T08:48:28+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:28 volumio go-librespot[21929]: time="2026-01-28T08:48:28+07:00" level=debug msg="completed challenge" Jan 28 08:48:28 volumio sudo[21964]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:28 volumio go-librespot[21929]: time="2026-01-28T08:48:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 08:48:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:29 volumio volumio[21756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:48:29 volumio volumio[21756]: info: [1769564909358] CoreMusicLibrary::Adding element YouTube Music Jan 28 08:48:29 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:48:29 volumio volumio[21756]: Cannot find translation for source YouTube Music Jan 28 08:48:29 volumio volumio[21756]: info: Volumio Calling Home Jan 28 08:48:29 volumio sudo[21981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 08:48:29 volumio sudo[21981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:29 volumio sudo[21981]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:29 volumio volumio[21878]: Starting albumart workers Jan 28 08:48:29 volumio volumio[21877]: Starting albumart workers Jan 28 08:48:29 volumio volumio[21876]: Starting albumart workers Jan 28 08:48:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:30 volumio volumio[21756]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 08:48:30 volumio volumio[21756]: info: Discovery: Found device Volumio Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::volumioGetState Jan 28 08:48:30 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:30 volumio volumio[21756]: info: MPD Permissions set Jan 28 08:48:30 volumio volumio[21756]: info: MPD Permissions set Jan 28 08:48:30 volumio volumio[21756]: info: Upmpdcli Daemon Started Jan 28 08:48:30 volumio volumio[21756]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 08:48:30 volumio volumio[21756]: info: Discovery: Found device Volumio Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::volumioGetState Jan 28 08:48:30 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:30 volumio volumio[21756]: info: Volumio called home Jan 28 08:48:30 volumio volumio[21756]: info: Spotify config file written Jan 28 08:48:30 volumio volumio[21756]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio sudo[21988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio sudo[21988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:30 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 08:48:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:30 volumio volumio[21756]: info: No need to fix Spotify hosts Jan 28 08:48:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:30 volumio go-librespot[22000]: go-librespot daemon starting... Jan 28 08:48:30 volumio sudo[21988]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+07:00" level=debug msg="app state loaded" Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+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]" Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+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]" Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+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]" Jan 28 08:48:31 volumio go-librespot[22001]: time="2026-01-28T08:48:31+07:00" level=info msg="zeroconf server listening on port 40609" Jan 28 08:48:32 volumio go-librespot[22001]: time="2026-01-28T08:48:32+07:00" level=debug msg="obtained new client token: AAA+89Wpc2Yjv/uHCUnGnTqss5z9t6DMn9cYRfmxHPntipgCa2yQ45BbeRIEevzZd/pSjel1u/DuA08YvIbIjIbkbIIbSICY1XoF0/pZHsRvM4U2BwOlntd9QaUH14RSYfHPyEnqKGQI/4yutIuHo74vQ4IdFRP7wI70m9mZdqhHGR4JYMoxfKaBFOOe5teCb1GeoLNQlwNzrrBrijb8xANdFiDJX+8p6ohHk0F6ITnQ/49PQpo9VySP" Jan 28 08:48:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:32 volumio go-librespot[22001]: time="2026-01-28T08:48:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:32 volumio volumio[21756]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 08:48:32 volumio volumio[21756]: SPOTIFY: BQDHLY5M1MNWbM_0GGUXInbcdbrRg43UI-nOeFeRt6-YptpHWKEARpLzNTPq2c46M2ANPPxaybRsKVlgdpqf10b4WvrsCEsockBGmZxVYeberlGcVIVq_V9CdhCO5r84IvbyXcEUtjzVW38egcQRQTobwjcprGyvzyJ0caAio4hRYzxvbEZAHq3761dGFM5MTf1PpZzZx_itfPUh2mrf_dK_qT7wB5R-SlL127V4sXzhebU-eTuJ_2fnY3r6v791F71Y44YdSgulOKj7bi8mWBGwBW5cDY9OJ91uEBwSFcnijmZ5AFHwDULy Jan 28 08:48:32 volumio volumio[21756]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 08:48:32 volumio volumio[21756]: info: New Spotify access token = BQDHLY5M1MNWbM_0GGUXInbcdbrRg43UI-nOeFeRt6-YptpHWKEARpLzNTPq2c46M2ANPPxaybRsKVlgdpqf10b4WvrsCEsockBGmZxVYeberlGcVIVq_V9CdhCO5r84IvbyXcEUtjzVW38egcQRQTobwjcprGyvzyJ0caAio4hRYzxvbEZAHq3761dGFM5MTf1PpZzZx_itfPUh2mrf_dK_qT7wB5R-SlL127V4sXzhebU-eTuJ_2fnY3r6v791F71Y44YdSgulOKj7bi8mWBGwBW5cDY9OJ91uEBwSFcnijmZ5AFHwDULy Jan 28 08:48:32 volumio volumio[21756]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 08:48:32 volumio go-librespot[22001]: time="2026-01-28T08:48:32+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:32 volumio go-librespot[22001]: time="2026-01-28T08:48:32+07:00" level=debug msg="completed challenge" Jan 28 08:48:32 volumio volumio[21756]: info: Starting Shairport Sync Jan 28 08:48:32 volumio volumio[21756]: info: Starting Shairport Sync Jan 28 08:48:32 volumio go-librespot[22001]: time="2026-01-28T08:48:32+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 " Jan 28 08:48:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:32 volumio volumio[21756]: info: Starting Shairport Sync Jan 28 08:48:32 volumio sudo[22028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:48:32 volumio sudo[22028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:32 volumio sudo[22031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:48:32 volumio sudo[22031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:32 volumio sudo[22034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 08:48:32 volumio sudo[22034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 08:48:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 08:48:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:48:32 volumio systemd[1]: shairport-sync.service: Consumed 2.279s CPU time. Jan 28 08:48:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:48:32 volumio sudo[22028]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:32 volumio volumio[21756]: info: Shairport-Sync Started Jan 28 08:48:32 volumio volumio[21756]: Error adding Membership: Error: addMembership EINVAL Jan 28 08:48:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 08:48:32 volumio volumio[21756]: info: CoreCommandRouter::volumioGetState Jan 28 08:48:32 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 08:48:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:48:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 08:48:33 volumio sudo[22031]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:33 volumio sudo[22034]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:33 volumio volumio[21756]: info: Shairport-Sync Started Jan 28 08:48:33 volumio volumio[21756]: info: Shairport-Sync Started Jan 28 08:48:33 volumio volumio[21756]: 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"} Jan 28 08:48:33 volumio volumio[21756]: info: Spotify Successfully logged in Jan 28 08:48:33 volumio volumio[21756]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 08:48:33 volumio volumio[21756]: info: [1769564913237] CoreMusicLibrary::Adding element Spotify Jan 28 08:48:33 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 08:48:33 volumio volumio[21756]: Cannot find translation for source YouTube Music Jan 28 08:48:33 volumio volumio[21756]: Cannot find translation for source Spotify Jan 28 08:48:33 volumio volumio[21756]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 08:48:33 volumio volumio[21756]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 08:48:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:34 volumio volumio[21756]: info: VolumeController:: Volume=100 Mute =false Jan 28 08:48:34 volumio volumio[21756]: info: CoreCommandRouter::volumioGetState Jan 28 08:48:34 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:34 volumio volumio[21756]: info: CoreStateMachine::pushState Jan 28 08:48:34 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:34 volumio volumio[21756]: info: CoreCommandRouter::volumioPushState Jan 28 08:48:35 volumio volumio[21756]: info: go-librespot daemon successfully initialized Jan 28 08:48:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Jan 28 08:48:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:35 volumio mpd[21979]: 2026-01-28T08:48:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 08:48:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:35 volumio go-librespot[22073]: go-librespot daemon starting... Jan 28 08:48:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 08:48:35 volumio sudo[21938]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:35 volumio sudo[21949]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:35 volumio go-librespot[22076]: time="2026-01-28T08:48:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:35 volumio go-librespot[22076]: time="2026-01-28T08:48:35+07:00" level=debug msg="app state loaded" Jan 28 08:48:35 volumio go-librespot[22076]: time="2026-01-28T08:48:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:35 volumio volumio[21756]: error: MPD error: The expression evaluated to a falsy value: Jan 28 08:48:35 volumio volumio[21756]: assert.ok(self.idling) Jan 28 08:48:35 volumio volumio[21756]: error: The expression evaluated to a falsy value: Jan 28 08:48:35 volumio volumio[21756]: assert.ok(self.idling) Jan 28 08:48:35 volumio volumio[21756]: error: updateQueue error: null Jan 28 08:48:35 volumio volumio[21756]: info: Completed starting Core Plugins Jan 28 08:48:35 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:35 volumio volumio[21756]: info: ----- MyVolumio plugins startup ---- Jan 28 08:48:35 volumio volumio[21756]: info: ------------------------------------------- Jan 28 08:48:35 volumio volumio[21756]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 08:48:35 volumio volumio[21756]: info: MPD running with PID21979 Jan 28 08:48:35 volumio volumio[21756]: ,establishing connection Jan 28 08:48:36 volumio volumio[21756]: error: updateQueue error: null Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48: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-gew4.spotify.com:80]" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+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]" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+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]" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+07:00" level=info msg="zeroconf server listening on port 33421" Jan 28 08:48:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+07:00" level=debug msg="obtained new client token: AACJe7nMBNdIKu0H+nfMhb5vA0/gOeVUilFZ1VCLTDrlwEsYvcwIaWq6wGNeUOPkt9t45aackoXgChT4GVIplWbjudS51T3soi51+R6T40EjJ00V6BuSDhxfJg0m2PrAZUNXhMiN8oX+jPMNlsCLyhz2PIzE0Z7xoe8o25Uc86XJi5UuYoSsNJrAddTR0M6J3IMYgf4gkFWBVz7N6VT/L6K5K94hMdGRZpfxzBdNkwEb9zEd7pqOYoxGpEg=" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+07:00" level=debug msg="completed challenge" Jan 28 08:48:36 volumio go-librespot[22076]: time="2026-01-28T08:48:36+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 " Jan 28 08:48:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:38 volumio volumio[21756]: info: Initializing connection to go-librespot Websocket Jan 28 08:48:38 volumio volumio[21756]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:48:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Jan 28 08:48:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:39 volumio go-librespot[22086]: go-librespot daemon starting... Jan 28 08:48:39 volumio go-librespot[22087]: time="2026-01-28T08:48:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:39 volumio go-librespot[22087]: time="2026-01-28T08:48:39+07:00" level=debug msg="app state loaded" Jan 28 08:48:39 volumio go-librespot[22087]: time="2026-01-28T08:48:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48: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-gew4.spotify.com:80]" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+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]" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+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]" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+07:00" level=info msg="zeroconf server listening on port 42415" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+07:00" level=debug msg="obtained new client token: AACbF+F90jlivihO9/KKPlKq/9XNXSU44v5lF65y78Bc4UFiT3z0twa45n4CJ+NQW+9F/tn11T6sXaGmSCZENo9IFWPkslnddQo6nvrb4GbBYOGAIUE8SAGhtRnNzS7uRzuSYIRvWqgrf9COnmwWpEJh7m5HqW4hF/EnIo/gvolWaKcQrFmEcw65mMncpG4PPkGykWjFBKCAwwYOy8IMm26pRqibT/NxmHo9u/HYc/kvalVikZpapxDu89s=" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:40 volumio volumio[21756]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+07:00" level=debug msg="completed challenge" Jan 28 08:48:40 volumio go-librespot[22087]: time="2026-01-28T08:48:40+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 " Jan 28 08:48:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:41 volumio volumio[21756]: info: Initializing connection to go-librespot Websocket Jan 28 08:48:41 volumio volumio[21756]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 08:48:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Jan 28 08:48:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:44 volumio go-librespot[22094]: go-librespot daemon starting... Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=debug msg="app state loaded" Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:44 volumio volumio[21756]: info: Initializing connection to go-librespot Websocket Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=debug msg="new websocket client" Jan 28 08:48:44 volumio volumio[21756]: info: Connection to go-librespot Websocket established Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+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]" Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+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]" Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+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]" Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=info msg="zeroconf server listening on port 44359" Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 08:48:44 volumio volumio[21756]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=debug msg="obtained new client token: AADX4JYepV5WFUX5ZwM6o88G5I3AOktpuXFUK23eUS5X9UUUK7sXCe1PxgQHpDmtIxSORX3RoNrt0RN5iWTTUf05JZw95g2U/evEyDqknWHjeYl9MODGbVpP4w+zWAiNxLDoFykBJMXnMjtmKaFJ964SCdzBNLc1IUXpdKpOvKehPzK4JCOjcZXSmKx99zzh5zJWV5+piWBSJrtbpEY8RnzsFUzCWvS9WOhnInruue7DmXDkl/42uR5tJAI=" Jan 28 08:48:44 volumio go-librespot[22095]: time="2026-01-28T08:48:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:45 volumio go-librespot[22095]: time="2026-01-28T08:48:45+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:45 volumio go-librespot[22095]: time="2026-01-28T08:48:45+07:00" level=debug msg="completed challenge" Jan 28 08:48:45 volumio go-librespot[22095]: time="2026-01-28T08:48: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 " Jan 28 08:48:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:46 volumio volumio[21756]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 08:48:46 volumio volumio[21756]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 08:48:46 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:46 volumio volumio[21756]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 08:48:46 volumio volumio[21756]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 08:48:46 volumio volumio[21756]: info: MyVolumio login type: Token Jan 28 08:48:46 volumio volumio[21756]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 08:48:46 volumio volumio[21756]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 08:48:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Jan 28 08:48:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 08:48:48 volumio go-librespot[22116]: go-librespot daemon starting... Jan 28 08:48:48 volumio volumio[21756]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 08:48:48 volumio volumio[21756]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 08:48:48 volumio volumio[21756]: info: Streaming services startup Jan 28 08:48:48 volumio volumio[21756]: info: Starting Streaming Daemon Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48:48+07:00" level=debug msg="app state loaded" Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 08:48:48 volumio sudo[22126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 08:48:48 volumio sudo[22126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 08:48:48 volumio volumio[21756]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 08:48:48 volumio sudo[22126]: pam_unix(sudo:session): session closed for user root Jan 28 08:48:48 volumio volumio[21756]: info: Getting Spotify volume Jan 28 08:48:48 volumio volumio[21756]: info: Connection to go-librespot Websocket closed Jan 28 08:48:48 volumio volumio[21756]: error: Cannot start Volumio Streaming Daemon Jan 28 08:48:48 volumio volumio[21756]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 08:48:48 volumio volumio[21756]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 08:48:48 volumio volumio[21756]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 08:48:48 volumio volumio[21756]: info: CoreCommandRouter::volumioGetState Jan 28 08:48:48 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:48 volumio volumio[21756]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 08:48:48 volumio volumio[21756]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 08:48:48 volumio volumio[21756]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 08:48:48 volumio volumio[21756]: info: Aligning Spotify Volume to Volumio Volume Jan 28 08:48:48 volumio volumio[21756]: info: CoreCommandRouter::volumioGetState Jan 28 08:48:48 volumio volumio[21756]: info: CorePlayQueue::getTrack 0 Jan 28 08:48:48 volumio volumio[21756]: info: Setting Spotify Volume from Volumio: 100 Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48:48+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]" Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48:48+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]" Jan 28 08:48:48 volumio go-librespot[22117]: time="2026-01-28T08:48:48+07:00" level=info msg="zeroconf server listening on port 36089" Jan 28 08:48:49 volumio go-librespot[22117]: time="2026-01-28T08:48:49+07:00" level=debug msg="obtained new client token: AAA2DE6eV1jY+z+SJLmdH0IPWeBUePavsUzv8eC7xld+qo46v6ZenQQX4540n6BsbJ+CYEb3grqWZR2ckNHG1OaGe5tRmbVnVLf1ELWvtwoZj2+WcSocPSr5TN/duPjW7dXDwLiaXkgZqLIQzqFz8ZVcdwRu6tJ9/K+EW9Ff0hbswfyZPk1Dc8px16xeclVi6tPMhnsGzUuF2IckB3yDLF6qLg7XkuhCt5vIfHHBkJLvoqhkTJFmfZI6" Jan 28 08:48:49 volumio go-librespot[22117]: time="2026-01-28T08:48:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 08:48:49 volumio go-librespot[22117]: time="2026-01-28T08:48:49+07:00" level=debug msg="completed keyexchange" Jan 28 08:48:49 volumio go-librespot[22117]: time="2026-01-28T08:48:49+07:00" level=debug msg="completed challenge" Jan 28 08:48:49 volumio go-librespot[22117]: time="2026-01-28T08:48:49+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 " Jan 28 08:48:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 08:48:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 08:48:49 volumio volumio[21756]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 08:48:49 volumio volumio[21756]: Error: socket hang up Jan 28 08:48:49 volumio volumio[21756]: at connResetException (node:internal/errors:720:14) Jan 28 08:48:49 volumio volumio[21756]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 08:48:49 volumio volumio[21756]: at Socket.emit (node:events:526:35) Jan 28 08:48:49 volumio volumio[21756]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 08:48:49 volumio volumio[21756]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 08:48:49 volumio volumio[21756]: code: 'ECONNRESET', Jan 28 08:48:49 volumio volumio[21756]: response: undefined Jan 28 08:48:49 volumio volumio[21756]: } Jan 28 08:48:49 volumio volumio[21756]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 08:48:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 08:48:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 08:48:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 08:48:50 volumio sudo[22148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 08:47' Jan 28 08:48:50 volumio sudo[22148]: 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"