Jan 28 16:58:00 volumio sudo[10688]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 16:58:00 volumio sudo[10688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:00 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "wizard"... Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "networkfs"... Jan 28 16:58:00 volumio volumio[10629]: info: Starting Udev Watcher for removable devices Jan 28 16:58:00 volumio volumio[10629]: info: Ignoring mount for partition: boot Jan 28 16:58:00 volumio volumio[10629]: info: Ignoring mount for partition: volumio Jan 28 16:58:00 volumio volumio[10629]: info: Ignoring mount for partition: volumio_data Jan 28 16:58:00 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "volumio_command_line_client"... Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "upnp"... Jan 28 16:58:00 volumio volumio[10629]: info: [1769594280245] Starting Upmpd Daemon Jan 28 16:58:00 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "my_music"... Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "mpd"... Jan 28 16:58:00 volumio volumio[10629]: info: Loading plugin "upnp_browser"... Jan 28 16:58:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 16:58:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:02 volumio go-librespot[10707]: go-librespot daemon starting... Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=debug msg="app state loaded" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=info msg="zeroconf server listening on port 42143" Jan 28 16:58:02 volumio sudo[10688]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=debug msg="obtained new client token: AACY2VjB71x5BbPW67p7kbtok9PdwKDwUDNzSqR8TsyacFVXsEDNVjBZueT0sC28VGZosA9L4MK9x1VhwOcDdj/IpdUX0c+vaVyK1NjnGShT44YWR1CpckTw6qSB/U47VWLqB0n+USh73QDzL3Fuzx2Q81uv3JTw4nIZ6ANgC6y4twPODtlwxeNIbkVA22lI60xaDthYOY+B8UIFpFHo+UbPEJRpd+Cej07xt8LcQ5KFfXiRtz3ikpbVKY0=" Jan 28 16:58:02 volumio go-librespot[10708]: time="2026-01-28T16:58:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:03 volumio go-librespot[10708]: time="2026-01-28T16:58:03+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:03 volumio go-librespot[10708]: time="2026-01-28T16:58:03+07:00" level=debug msg="completed challenge" Jan 28 16:58:03 volumio go-librespot[10708]: time="2026-01-28T16:58:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:58:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:03 volumio volumio[10629]: info: Starting UPNP Browser Jan 28 16:58:03 volumio volumio[10629]: info: Loading plugin "alarm-clock"... Jan 28 16:58:04 volumio volumio[10629]: info: Loading plugin "airplay_emulation"... Jan 28 16:58:04 volumio volumio[10629]: info: Starting Shairport Sync Jan 28 16:58:04 volumio volumio[10629]: info: Loading plugin "last_100"... Jan 28 16:58:04 volumio volumio[10629]: info: Loading plugin "webradio"... Jan 28 16:58:04 volumio volumio[10629]: info: Loading plugin "i2s_dacs"... Jan 28 16:58:04 volumio volumio[10629]: info: Loading plugin "volumiodiscovery"... Jan 28 16:58:04 volumio volumio[10629]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:04 volumio volumio[10629]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:04 volumio node[10629]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:04 volumio volumio[10629]: *** WARNING *** For more information see Jan 28 16:58:04 volumio volumio[10629]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:04 volumio volumio[10629]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:04 volumio volumio[10629]: *** WARNING *** For more information see Jan 28 16:58:04 volumio node[10629]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:04 volumio node[10629]: *** WARNING *** For more information see Jan 28 16:58:04 volumio node[10629]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:04 volumio node[10629]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:04 volumio node[10629]: *** WARNING *** For more information see Jan 28 16:58:04 volumio volumio[10629]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 16:58:04 volumio volumio[10629]: info: Discovery: Started advertising with name: Volumio Jan 28 16:58:04 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:58:04 volumio volumio[10629]: info: Loading plugin "spop"... Jan 28 16:58:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 16:58:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:06 volumio go-librespot[10717]: go-librespot daemon starting... Jan 28 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+07:00" level=debug msg="app state loaded" Jan 28 16:58:06 volumio volumio[10629]: info: Loading plugin "ytcr"... Jan 28 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+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 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+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 16:58:06 volumio go-librespot[10718]: time="2026-01-28T16:58:06+07:00" level=info msg="zeroconf server listening on port 42731" Jan 28 16:58:07 volumio go-librespot[10718]: time="2026-01-28T16:58:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 503" Jan 28 16:58:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:09 volumio volumio[10629]: info: Loading plugin "ytmusic"... Jan 28 16:58:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:09 volumio volumio-remote-updater[628]: [2026-01-28 16:58:09] [connect] Successful connection Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "outputs"... Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "albumart"... Jan 28 16:58:10 volumio volumio[10629]: info: Plugin example_plugin is not enabled Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "inputs"... Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "updater_comm"... Jan 28 16:58:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 16:58:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:10 volumio go-librespot[10750]: go-librespot daemon starting... Jan 28 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58:10+07:00" level=debug msg="app state loaded" Jan 28 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:10 volumio volumio[10629]: info: Plugin mpdemulation is not enabled Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "rest_api"... Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "websocket"... Jan 28 16:58:10 volumio volumio[10629]: info: Starting Socket.io Server version 1.7.4 Jan 28 16:58:10 volumio volumio[10629]: info: Loading plugin "RoonBridge"... Jan 28 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58: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 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58: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 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58: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 16:58:10 volumio go-librespot[10751]: time="2026-01-28T16:58:10+07:00" level=info msg="zeroconf server listening on port 39755" Jan 28 16:58:11 volumio volumio[10629]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 16:58:11 volumio volumio[10629]: info: Loading i18n strings for locale en Jan 28 16:58:11 volumio volumio[10629]: Updating browse sources language Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:11 volumio go-librespot[10751]: time="2026-01-28T16:58:11+07:00" level=debug msg="obtained new client token: AAB9GItK26GLf4uDbmm4Yu4N36NGn2yCShVlswTIWZ5ZNHGnL1SgfNAduQlXJGAC57cBMmlhpXRhzjCQGNis6jjNrbP8NEyx4iCx7byvZK3qYkvGiBYS+qtBHg5js7+PAvnoTa1gJa/ZDiIPsZQeuf02fEhr5w1OUlDg1mY8BICtKxJAhD/eqPt01KCDIs14QmF09RjbFoNUbUWSKzZeA+Wf25LqWQX+j5bNcWSmd4o391BgcsoVa3ww" Jan 28 16:58:11 volumio go-librespot[10751]: time="2026-01-28T16:58:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:11 volumio go-librespot[10751]: time="2026-01-28T16:58:11+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:11 volumio go-librespot[10751]: time="2026-01-28T16:58:11+07:00" level=debug msg="completed challenge" Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::initPlayerControls Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:58:11 volumio volumio[10741]: Forking 3 albumart workers Jan 28 16:58:11 volumio volumio[10629]: Express server listening on port 3000 Jan 28 16:58:11 volumio volumio[10629]: [Metrics] WebUI: 16s 85.51ms Jan 28 16:58:11 volumio go-librespot[10751]: time="2026-01-28T16:58:11+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 16:58:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:11 volumio volumio[10629]: info: CoreStateMachine::resetVolumioState Jan 28 16:58:11 volumio volumio[10629]: info: CoreStateMachine::getcurrentVolume Jan 28 16:58:11 volumio volumio[10629]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:58:11 volumio sudo[10791]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:58:11 volumio sudo[10791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:11 volumio sudo[10791]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:11 volumio sudo[10793]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:58:11 volumio sudo[10793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:11 volumio volumio[10629]: info: Volumio Network Manager: Network status updated: 1 Jan 28 16:58:11 volumio sudo[10793]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:12 volumio volumio[10629]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::pushState Jan 28 16:58:12 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::updateTrackBlock Jan 28 16:58:12 volumio volumio[10629]: info: CorePlayQueue::getTrackBlock Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:58:12 volumio volumio-remote-updater[628]: [2026-01-28 16:58:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769594289 101 Jan 28 16:58:12 volumio volumio[10629]: 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 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:12 volumio volumio[10629]: info: Reloading queue from file Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::setRepeat null single undefined Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::pushState Jan 28 16:58:12 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::setRandom null Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::pushState Jan 28 16:58:12 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:12 volumio volumio[10629]: info: Setting Device type: Raspberry PI Jan 28 16:58:12 volumio volumio[10629]: info: Completed loading Core Plugins Jan 28 16:58:12 volumio volumio[10629]: info: Preparing to generate the ALSA configuration file Jan 28 16:58:12 volumio volumio[10629]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:58:12 volumio volumio[10629]: info: CoreStateMachine::pushState Jan 28 16:58:12 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:12 volumio volumio[10629]: info: Asound.conf file unchanged, so no further update is needed Jan 28 16:58:12 volumio volumio[10629]: info: Output device has changed, restarting MPD Jan 28 16:58:12 volumio volumio[10629]: info: Output device has changed, restarting Shairport Sync Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:12 volumio sudo[10809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 16:58:12 volumio sudo[10809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:12 volumio sudo[10811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:58:12 volumio sudo[10811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:12 volumio sudo[10811]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:12 volumio volumio[10629]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:58:12 volumio sudo[10813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:58:12 volumio volumio[10629]: info: ___________ START PLUGINS ___________ Jan 28 16:58:12 volumio sudo[10813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:12 volumio volumio[10629]: info: ControllerMpd::onStart: Initializing MPD Jan 28 16:58:12 volumio volumio[10629]: info: Creating MPD Configuration file Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:12 volumio volumio[10629]: info: [1769594292835] CoreMusicLibrary::Adding element Media Servers Jan 28 16:58:12 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:12 volumio sudo[10809]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:12 volumio sudo[10822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:58:12 volumio sudo[10822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:12 volumio sudo[10822]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:12 volumio sudo[10824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:58:12 volumio volumio[10629]: info: UPNP Browser: Client initialized successfully Jan 28 16:58:12 volumio sudo[10824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:12 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:13 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:58:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:58:13 volumio systemd[1]: mpd.service: Consumed 7.347s CPU time. Jan 28 16:58:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:58:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:58:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:58:13 volumio volumio[10629]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:58:13 volumio volumio[10629]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:13 volumio volumio[10629]: info: [1769594293220] CoreMusicLibrary::Adding element Last_100 Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:13 volumio volumio[10629]: info: [1769594293230] CoreMusicLibrary::Adding element Webradio Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:58:13 volumio volumio[10629]: info: Initializing BBC Radios Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:13 volumio volumio[10629]: info: Creating Spotify config file Jan 28 16:58:13 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:13 volumio sudo[10836]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 16:58:13 volumio sudo[10836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 16:58:13 volumio sudo[10836]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:14 volumio volumio[10760]: Starting albumart workers Jan 28 16:58:14 volumio volumio[10763]: Starting albumart workers Jan 28 16:58:14 volumio volumio[10629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:14 volumio volumio[10629]: info: [1769594294638] CoreMusicLibrary::Adding element YouTube Music Jan 28 16:58:14 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:14 volumio volumio[10629]: Cannot find translation for source YouTube Music Jan 28 16:58:14 volumio volumio[10629]: info: Volumio Calling Home Jan 28 16:58:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 16:58:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:14 volumio sudo[10853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 16:58:14 volumio sudo[10853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:14 volumio go-librespot[10856]: go-librespot daemon starting... Jan 28 16:58:14 volumio go-librespot[10858]: time="2026-01-28T16:58:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:14 volumio sudo[10853]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:15 volumio volumio[10764]: Starting albumart workers Jan 28 16:58:15 volumio volumio[10629]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:58:15 volumio volumio[10629]: info: Discovery: Found device Volumio Jan 28 16:58:15 volumio volumio[10629]: info: CoreCommandRouter::volumioGetState Jan 28 16:58:15 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:15 volumio volumio[10629]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:58:15 volumio volumio[10629]: info: Discovery: Found device Volumio Jan 28 16:58:15 volumio volumio[10629]: info: CoreCommandRouter::volumioGetState Jan 28 16:58:15 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:15 volumio go-librespot[10858]: time="2026-01-28T16:58:15+07:00" level=info msg="zeroconf server listening on port 46105" Jan 28 16:58:15 volumio volumio[10629]: info: MPD Permissions set Jan 28 16:58:15 volumio volumio[10629]: info: MPD Permissions set Jan 28 16:58:15 volumio volumio[10629]: info: Upmpdcli Daemon Started Jan 28 16:58:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:15 volumio volumio[10629]: info: Volumio called home Jan 28 16:58:15 volumio volumio[10629]: info: Spotify config file written Jan 28 16:58:15 volumio sudo[10867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 16:58:15 volumio sudo[10867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:16 volumio volumio[10629]: 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 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 16:58:16 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 16:58:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio go-librespot[10874]: go-librespot daemon starting... Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio sudo[10867]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:16 volumio go-librespot[10875]: time="2026-01-28T16:58:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:16 volumio go-librespot[10875]: time="2026-01-28T16:58:16+07:00" level=debug msg="app state loaded" Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:16 volumio go-librespot[10875]: time="2026-01-28T16:58:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:16 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:16 volumio volumio[10629]: info: No need to fix Spotify hosts Jan 28 16:58:16 volumio go-librespot[10875]: time="2026-01-28T16:58:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:58:16 volumio go-librespot[10875]: time="2026-01-28T16:58:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:58:16 volumio go-librespot[10875]: time="2026-01-28T16:58:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:58:17 volumio go-librespot[10875]: time="2026-01-28T16:58:17+07:00" level=info msg="zeroconf server listening on port 40557" Jan 28 16:58:17 volumio go-librespot[10875]: time="2026-01-28T16:58:17+07:00" level=debug msg="obtained new client token: AAB2vCNA15n77l1yuYIoA/VMNdL714ogcYIQQ3+Wrwmi75qVnFwzco0fL7/gnznYZtfeifN0Bkf5j5wJFRhdi4P8YJNx3+cvaspqoA4mhEK5rbZskVpPl+Hj3J2qGW77U2t98f5/zVLAuGjxvmoo2bG6gm4hYFjvZq8Fs6oyCK10iqXwMClVMEbg6sEOLbm2q9/a/p77+bQTrTPemnKAMXoQum2bcmIeO1ws+614kZwBtIGcefv2jvCY" Jan 28 16:58:17 volumio go-librespot[10875]: time="2026-01-28T16:58:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:17 volumio go-librespot[10875]: time="2026-01-28T16:58:17+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:17 volumio go-librespot[10875]: time="2026-01-28T16:58:17+07:00" level=debug msg="completed challenge" Jan 28 16:58:17 volumio go-librespot[10875]: time="2026-01-28T16:58:17+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 16:58:17 volumio volumio[10629]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:58:17 volumio volumio[10629]: SPOTIFY: BQAb-VMZvegZSHE894siMihg4LlbwnaQsgvk7NKXnINsRheNZ1BCXxLlztEy9qKTPqDvy6lO6CU9VXMKFqmqOMV56RHpJA9TpSAJuRHNgDPUTYC4GaY4am8Or5a-a0OV03V8-_Q-PIBFv687xE0JF2tCEzKDm86W-4cB23UtKveocilzsUiZHxMSK2D4-30R2kypeQBE5W_-B4a5uDmhf9FRUzsVSMmTt8M8pLktVRnE1QRzncQx_mEY97aj9dOHKn9C-VSgUHEMh2iWLYeqUnTG0ROcepf0nF74duIRa9qNkrn9G61zzky5 Jan 28 16:58:17 volumio volumio[10629]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:58:17 volumio volumio[10629]: info: New Spotify access token = BQAb-VMZvegZSHE894siMihg4LlbwnaQsgvk7NKXnINsRheNZ1BCXxLlztEy9qKTPqDvy6lO6CU9VXMKFqmqOMV56RHpJA9TpSAJuRHNgDPUTYC4GaY4am8Or5a-a0OV03V8-_Q-PIBFv687xE0JF2tCEzKDm86W-4cB23UtKveocilzsUiZHxMSK2D4-30R2kypeQBE5W_-B4a5uDmhf9FRUzsVSMmTt8M8pLktVRnE1QRzncQx_mEY97aj9dOHKn9C-VSgUHEMh2iWLYeqUnTG0ROcepf0nF74duIRa9qNkrn9G61zzky5 Jan 28 16:58:17 volumio volumio[10629]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 16:58:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:17 volumio volumio[10629]: info: Starting Shairport Sync Jan 28 16:58:17 volumio volumio[10629]: info: Starting Shairport Sync Jan 28 16:58:17 volumio volumio[10629]: info: Starting Shairport Sync Jan 28 16:58:17 volumio sudo[10909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:58:17 volumio sudo[10909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:17 volumio sudo[10911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:58:17 volumio sudo[10911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:17 volumio sudo[10913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:58:17 volumio sudo[10913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 16:58:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 16:58:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:58:17 volumio systemd[1]: shairport-sync.service: Consumed 2.313s CPU time. Jan 28 16:58:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:58:18 volumio sudo[10911]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:18 volumio sudo[10909]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:18 volumio sudo[10913]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:18 volumio volumio[10629]: info: Shairport-Sync Started Jan 28 16:58:18 volumio volumio[10629]: Error adding Membership: Error: addMembership EINVAL Jan 28 16:58:18 volumio volumio[10629]: info: Shairport-Sync Started Jan 28 16:58:18 volumio volumio[10629]: info: Shairport-Sync Started Jan 28 16:58:18 volumio volumio[10629]: info: CoreCommandRouter::volumioGetState Jan 28 16:58:18 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:18 volumio volumio[10629]: 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 16:58:18 volumio volumio[10629]: info: Spotify Successfully logged in Jan 28 16:58:18 volumio volumio[10629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:18 volumio volumio[10629]: info: [1769594298545] CoreMusicLibrary::Adding element Spotify Jan 28 16:58:18 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:18 volumio volumio[10629]: Cannot find translation for source YouTube Music Jan 28 16:58:18 volumio volumio[10629]: Cannot find translation for source Spotify Jan 28 16:58:19 volumio volumio[10629]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 16:58:19 volumio volumio[10629]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:58:19 volumio volumio[10629]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:58:19 volumio volumio[10629]: info: CoreCommandRouter::volumioGetState Jan 28 16:58:19 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:19 volumio volumio[10629]: info: CoreStateMachine::pushState Jan 28 16:58:19 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:19 volumio volumio[10629]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:20 volumio volumio[10629]: info: go-librespot daemon successfully initialized Jan 28 16:58:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 16:58:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:20 volumio go-librespot[10950]: go-librespot daemon starting... Jan 28 16:58:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:20 volumio go-librespot[10951]: time="2026-01-28T16:58:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:20 volumio go-librespot[10951]: time="2026-01-28T16:58:20+07:00" level=debug msg="app state loaded" Jan 28 16:58:20 volumio go-librespot[10951]: time="2026-01-28T16:58:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:21 volumio mpd[10851]: 2026-01-28T16:58:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 16:58:21 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 16:58:21 volumio sudo[10813]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:21 volumio sudo[10824]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:21 volumio volumio[10629]: error: MPD error: The expression evaluated to a falsy value: Jan 28 16:58:21 volumio volumio[10629]: assert.ok(self.idling) Jan 28 16:58:21 volumio volumio[10629]: error: The expression evaluated to a falsy value: Jan 28 16:58:21 volumio volumio[10629]: assert.ok(self.idling) Jan 28 16:58:21 volumio volumio[10629]: error: updateQueue error: null Jan 28 16:58:21 volumio volumio[10629]: info: MPD running with PID10851 Jan 28 16:58:21 volumio volumio[10629]: ,establishing connection Jan 28 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+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 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+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 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+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 16:58:21 volumio volumio[10629]: info: Completed starting Core Plugins Jan 28 16:58:21 volumio volumio[10629]: info: ------------------------------------------- Jan 28 16:58:21 volumio volumio[10629]: info: ----- MyVolumio plugins startup ---- Jan 28 16:58:21 volumio volumio[10629]: info: ------------------------------------------- Jan 28 16:58:21 volumio volumio[10629]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+07:00" level=info msg="zeroconf server listening on port 42527" Jan 28 16:58:21 volumio volumio[10629]: error: updateQueue error: null Jan 28 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+07:00" level=debug msg="obtained new client token: AACj5cs8Rwwp3T6xP/ounKJCFMtCGcH+k+6cYv2aVytxaxJeeLoIF1B3S1VU9zeXZiUrbZ8vVGEgttbYC1KZwh6wOPkNeT4SvxK4yh6g4M8rfCs7wNeX+7dFh6VbhRiPhLTMOoWUGCZVjtezOfoVGLESdj7yfp7CsqArGMFUYzBsqZxOlT0ASnUSALl9B7JYvh2JU4p7l3idrRHG5p9oq3QHwS7ociEMquHHj1X3d8nFLwqmCxs1h0yRiCw=" Jan 28 16:58:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:21 volumio go-librespot[10951]: time="2026-01-28T16:58:21+07:00" level=debug msg="completed challenge" Jan 28 16:58:22 volumio go-librespot[10951]: time="2026-01-28T16:58: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 16:58:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:23 volumio volumio[10629]: info: Initializing connection to go-librespot Websocket Jan 28 16:58:23 volumio volumio[10629]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:58:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 16:58:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:25 volumio go-librespot[10962]: go-librespot daemon starting... Jan 28 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+07:00" level=debug msg="app state loaded" Jan 28 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+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 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+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 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+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 16:58:25 volumio go-librespot[10963]: time="2026-01-28T16:58:25+07:00" level=info msg="zeroconf server listening on port 40901" Jan 28 16:58:26 volumio go-librespot[10963]: time="2026-01-28T16:58:26+07:00" level=debug msg="obtained new client token: AACoW6Y9wNlr0sYfZSHbJJCM88iBvxJQhgJg9cdt1JxUMBQUK+fGg4AC81Zb/AZQSbsCbxTCsMpne0emlNhVqyMwN/mxrSlRGF/5lelyAdUZNSmXPLSPZRQGk7+YPqlNVzrtmsKTY8saJqZkqbzcUu4KJqDWRJ3JDWACo95SLKW4DOhle5zNCPDFSUg6nZfLZpMzM45dLscFFI3tM5MmGKvpYz6sTnC23twudlXtHANWgVMxouQjr00A" Jan 28 16:58:26 volumio volumio[10629]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 16:58:26 volumio go-librespot[10963]: time="2026-01-28T16:58:26+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 16:58:26 volumio go-librespot[10963]: time="2026-01-28T16:58:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 16:58:26 volumio go-librespot[10963]: time="2026-01-28T16:58:26+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:26 volumio go-librespot[10963]: time="2026-01-28T16:58:26+07:00" level=debug msg="completed challenge" Jan 28 16:58:26 volumio go-librespot[10963]: time="2026-01-28T16:58: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 16:58:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:26 volumio volumio[10629]: info: Initializing connection to go-librespot Websocket Jan 28 16:58:26 volumio volumio[10629]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:58:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 16:58:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:29 volumio go-librespot[10971]: go-librespot daemon starting... Jan 28 16:58:29 volumio go-librespot[10972]: time="2026-01-28T16:58:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:29 volumio go-librespot[10972]: time="2026-01-28T16:58:29+07:00" level=debug msg="app state loaded" Jan 28 16:58:29 volumio go-librespot[10972]: time="2026-01-28T16:58:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:29 volumio volumio[10629]: info: Initializing connection to go-librespot Websocket Jan 28 16:58:29 volumio go-librespot[10972]: time="2026-01-28T16:58:29+07:00" level=debug msg="new websocket client" Jan 28 16:58:29 volumio volumio[10629]: info: Connection to go-librespot Websocket established Jan 28 16:58:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58: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 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58: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 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58: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 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58:30+07:00" level=info msg="zeroconf server listening on port 34191" Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 16:58:30 volumio volumio[10629]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58:30+07:00" level=debug msg="obtained new client token: AAB4Li9OGLekp+PZnnq1IfwPn9u7e9MtPLsPCryxFkG0+muTsNoktbCmB/2ExudVFxx+tQHBE7cn/mUsUz9NIyQgdMCyBt86/oQ0NJbI0kqcYbyqJJbgfC+u586ym97raCFl/iEwIfIklC7NLyBMb/PRAqyqRfhn2sJqAXQdsw7bQjfraZ0G01H9wupR7aCTjNWvE2zMCX/lxEW04eBDqURH4B4mErx2AH9BtMi0Pa6MPhkItsskKtk1rAM=" Jan 28 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58:30+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58:30+07:00" level=debug msg="completed challenge" Jan 28 16:58:30 volumio go-librespot[10972]: time="2026-01-28T16:58:30+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 16:58:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:32 volumio volumio[10629]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 16:58:32 volumio volumio[10629]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 16:58:32 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:32 volumio volumio[10629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:32 volumio volumio[10629]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 16:58:32 volumio volumio[10629]: info: MyVolumio login type: Token Jan 28 16:58:32 volumio volumio[10629]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 16:58:32 volumio volumio[10629]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 16:58:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 16:58:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:33 volumio go-librespot[10993]: go-librespot daemon starting... Jan 28 16:58:33 volumio go-librespot[10994]: time="2026-01-28T16:58:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:33 volumio go-librespot[10994]: time="2026-01-28T16:58:33+07:00" level=debug msg="app state loaded" Jan 28 16:58:33 volumio go-librespot[10994]: time="2026-01-28T16:58:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:33 volumio volumio[10629]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 16:58:33 volumio volumio[10629]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 16:58:33 volumio volumio[10629]: info: Streaming services startup Jan 28 16:58:33 volumio volumio[10629]: info: Starting Streaming Daemon Jan 28 16:58:33 volumio sudo[11003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 16:58:33 volumio sudo[11003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:33 volumio volumio[10629]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 16:58:34 volumio sudo[11003]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:34 volumio volumio[10629]: info: Getting Spotify volume Jan 28 16:58:34 volumio volumio[10629]: info: Connection to go-librespot Websocket closed Jan 28 16:58:34 volumio volumio[10629]: error: Cannot start Volumio Streaming Daemon Jan 28 16:58:34 volumio volumio[10629]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 16:58:34 volumio volumio[10629]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 16:58:34 volumio volumio[10629]: 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 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+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 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+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 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+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 16:58:34 volumio volumio[10629]: info: CoreCommandRouter::volumioGetState Jan 28 16:58:34 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:34 volumio volumio[10629]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 16:58:34 volumio volumio[10629]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 16:58:34 volumio volumio[10629]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 16:58:34 volumio volumio[10629]: info: Aligning Spotify Volume to Volumio Volume Jan 28 16:58:34 volumio volumio[10629]: info: CoreCommandRouter::volumioGetState Jan 28 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+07:00" level=info msg="zeroconf server listening on port 44655" Jan 28 16:58:34 volumio volumio[10629]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:34 volumio volumio[10629]: info: Setting Spotify Volume from Volumio: 100 Jan 28 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+07:00" level=debug msg="obtained new client token: AACDCohvTuULkyA698GwcX3Bul1ZbSwsre1XLmX4Il3ogoOtmbMreOoNkHhtbXmJUcYrj0rltkU1kSdN1U5lPKPX0BR4koQ34dUSSFrC/mYk4erkFZs43sypYqWKkP8WQ670HNSB1ZvTDsI670ztDtBoinzFbjRqCUkxHhmTUwt9/vD/HGhqPdtMyPAiTYBPrcs6L+nlnIhHvm0A3H1E9rDTmcEBdVLHr7IBRp02onCbyhv+ALWPMp4CX9o=" Jan 28 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+07:00" level=debug msg="completed challenge" Jan 28 16:58:34 volumio go-librespot[10994]: time="2026-01-28T16:58:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:58:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:34 volumio volumio[10629]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:58:34 volumio volumio[10629]: Error: socket hang up Jan 28 16:58:34 volumio volumio[10629]: at connResetException (node:internal/errors:720:14) Jan 28 16:58:34 volumio volumio[10629]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 16:58:34 volumio volumio[10629]: at Socket.emit (node:events:526:35) Jan 28 16:58:34 volumio volumio[10629]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 16:58:34 volumio volumio[10629]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 16:58:34 volumio volumio[10629]: code: 'ECONNRESET', Jan 28 16:58:34 volumio volumio[10629]: response: undefined Jan 28 16:58:34 volumio volumio[10629]: } Jan 28 16:58:34 volumio volumio[10629]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:58:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:36 volumio sudo[11024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 16:57' Jan 28 16:58:36 volumio sudo[11024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:36 volumio sudo[11024]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:36 volumio volumio-remote-updater[628]: [2026-01-28 16:58:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 16:58:36 volumio volumio-remote-updater[628]: [2026-01-28 16:58:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 16:58:36 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:36 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 16:58:36 volumio systemd[1]: volumio.service: Consumed 59.035s CPU time. Jan 28 16:58:37 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 16:58:37 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 16:58:37 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10424. Jan 28 16:58:37 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 16:58:37 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 16:58:37 volumio systemd[1]: volumio.service: Consumed 59.035s CPU time. Jan 28 16:58:37 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 16:58:37 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 16:58:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 16:58:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:38 volumio go-librespot[11051]: go-librespot daemon starting... Jan 28 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+07:00" level=debug msg="app state loaded" Jan 28 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+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 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+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 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+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 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+07:00" level=info msg="zeroconf server listening on port 39697" Jan 28 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+07:00" level=debug msg="obtained new client token: AABp2zRihaeb0kdxQd4pShSeNmigYj4tJIlHR7Uv+pjK5y7u2bp/InyugzjBNl4RHYijZiI2MpyEcf6X2ronOnLdHqGutVaBjTqMe1BQhTKXj67To0tnzbXxjjoNLIwfz55MZosy/0Qk+vvu6EnTcC4nEwQSwC4tZ1dFVnUZ2LrKHJkF6XrUVVX2NcAjpwZSOzzWLULOiYz3wyT7RzvDLMMRA8D9Z+Su4CdpEyNXFdtnwCagtncI0yxX3+M=" Jan 28 16:58:38 volumio go-librespot[11052]: time="2026-01-28T16:58:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:39 volumio go-librespot[11052]: time="2026-01-28T16:58:39+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:39 volumio go-librespot[11052]: time="2026-01-28T16:58:39+07:00" level=debug msg="completed challenge" Jan 28 16:58:39 volumio go-librespot[11052]: time="2026-01-28T16:58:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:58:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:40 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:58:40 volumio volumio[11036]: info: ----- Volumio3 ---- Jan 28 16:58:40 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:58:40 volumio volumio[11036]: info: ----- System startup ---- Jan 28 16:58:40 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:58:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:41 volumio volumio-remote-updater[628]: [2026-01-28 16:58:41] [connect] Successful connection Jan 28 16:58:42 volumio volumio[11036]: info: MYVOLUMIO Environment detected Jan 28 16:58:42 volumio volumio[11036]: info: Plugin folders cleanup Jan 28 16:58:42 volumio volumio[11036]: info: Scanning into folder /volumio/app/plugins/ Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category audio_interface Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category miscellanea Jan 28 16:58:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 16:58:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category music_service Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category plugins.json Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category system_controller Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category user_interface Jan 28 16:58:42 volumio volumio[11036]: info: Scanning into folder /data/plugins/ Jan 28 16:58:42 volumio volumio[11036]: info: Scanning category music_service Jan 28 16:58:42 volumio volumio[11036]: info: Plugin folders cleanup completed Jan 28 16:58:42 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:58:42 volumio volumio[11036]: info: ----- Core plugins startup ---- Jan 28 16:58:42 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:58:42 volumio volumio[11036]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 16:58:42 volumio volumio[11036]: info: Adding plugin upnp to MyMusic Plugins Jan 28 16:58:42 volumio volumio[11036]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 16:58:42 volumio volumio[11036]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 16:58:42 volumio volumio[11036]: info: Loading plugins from folder /data/plugins/ Jan 28 16:58:42 volumio volumio[11036]: info: Loading plugin "system"... Jan 28 16:58:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:42 volumio go-librespot[11069]: go-librespot daemon starting... Jan 28 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+07:00" level=debug msg="app state loaded" Jan 28 16:58:42 volumio volumio[11036]: info: Loading plugin "appearance"... Jan 28 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+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 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+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 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+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 16:58:42 volumio go-librespot[11070]: time="2026-01-28T16:58:42+07:00" level=info msg="zeroconf server listening on port 32851" Jan 28 16:58:43 volumio go-librespot[11070]: time="2026-01-28T16:58:43+07:00" level=debug msg="obtained new client token: AAAvVgsVTdSar5F46aWzQtRd2nXQi7A6KqXyhq69PRh8ww2Jx92hRB34aLhmAOEaEih3oT98xSY4DytOoEATJEe/dDuVjiyEvJN4mCUCVNd1nvCKiJQJvFvTGcTOytylmClbM3wP+yMEX2dKVlWP/3v+xKJGTpguunevdrvVkTct1FVNNfLjWzGdzpbfaS/2OuEaCM0XL1ra4wdQ3pWta6ua1VtEM0aVsSAsT46ktriObu4dYMJ5sTZ0" Jan 28 16:58:43 volumio go-librespot[11070]: time="2026-01-28T16:58:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:43 volumio go-librespot[11070]: time="2026-01-28T16:58:43+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:43 volumio go-librespot[11070]: time="2026-01-28T16:58:43+07:00" level=debug msg="completed challenge" Jan 28 16:58:43 volumio go-librespot[11070]: time="2026-01-28T16:58:43+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 16:58:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "network"... Jan 28 16:58:44 volumio volumio[11036]: info: Refreshing Cached IP Addresses Jan 28 16:58:44 volumio sudo[11081]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:58:44 volumio sudo[11081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "services"... Jan 28 16:58:44 volumio sudo[11083]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:58:44 volumio sudo[11083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "alsa_controller"... Jan 28 16:58:44 volumio sudo[11081]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:44 volumio sudo[11083]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:44 volumio sudo[11095]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 16:58:44 volumio sudo[11095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:44 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "wizard"... Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "networkfs"... Jan 28 16:58:44 volumio volumio[11036]: info: Starting Udev Watcher for removable devices Jan 28 16:58:44 volumio volumio[11036]: info: Ignoring mount for partition: boot Jan 28 16:58:44 volumio volumio[11036]: info: Ignoring mount for partition: volumio Jan 28 16:58:44 volumio volumio[11036]: info: Ignoring mount for partition: volumio_data Jan 28 16:58:44 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "volumio_command_line_client"... Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "upnp"... Jan 28 16:58:44 volumio volumio[11036]: info: [1769594324750] Starting Upmpd Daemon Jan 28 16:58:44 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "my_music"... Jan 28 16:58:44 volumio volumio[11036]: info: Loading plugin "mpd"... Jan 28 16:58:45 volumio volumio[11036]: info: Loading plugin "upnp_browser"... Jan 28 16:58:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 16:58:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:46 volumio go-librespot[11114]: go-librespot daemon starting... Jan 28 16:58:46 volumio go-librespot[11115]: time="2026-01-28T16:58:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:46 volumio go-librespot[11115]: time="2026-01-28T16:58:46+07:00" level=debug msg="app state loaded" Jan 28 16:58:46 volumio go-librespot[11115]: time="2026-01-28T16:58:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+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 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+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 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+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 16:58:47 volumio sudo[11095]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+07:00" level=info msg="zeroconf server listening on port 39329" Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+07:00" level=debug msg="obtained new client token: AAAYAKHoGAydio+rJRKU6Ug/t0VxgFWKmxUS3iab57k9xHv1MaDaGmWhgg6gkLCINh6DSLKK7ZoWZ8EQQSriBxR/RTtIcFR3WXugphX8VGEhHYKvn7r0pD22lmjKDxOTpEpurSYIvkfBxTrmJU+2ic6x53m9zs7FmJE+SIlcMEzYtm+Qr1y9CTbpFnP7rshc2V9Z6Z/kviCwh4ByrAnyl2Dm33nxbtrD9wwNAE+nnls+SGdWW/RzUYZfOCY=" Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+07:00" level=debug msg="completed challenge" Jan 28 16:58:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:47 volumio go-librespot[11115]: time="2026-01-28T16:58:47+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 16:58:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:48 volumio volumio[11036]: info: Starting UPNP Browser Jan 28 16:58:48 volumio volumio[11036]: info: Loading plugin "alarm-clock"... Jan 28 16:58:48 volumio volumio[11036]: info: Loading plugin "airplay_emulation"... Jan 28 16:58:48 volumio volumio[11036]: info: Starting Shairport Sync Jan 28 16:58:48 volumio volumio[11036]: info: Loading plugin "last_100"... Jan 28 16:58:48 volumio volumio[11036]: info: Loading plugin "webradio"... Jan 28 16:58:48 volumio volumio[11036]: info: Loading plugin "i2s_dacs"... Jan 28 16:58:48 volumio volumio[11036]: info: Loading plugin "volumiodiscovery"... Jan 28 16:58:49 volumio volumio[11036]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:49 volumio volumio[11036]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:49 volumio volumio[11036]: *** WARNING *** For more information see Jan 28 16:58:49 volumio volumio[11036]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:49 volumio volumio[11036]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:49 volumio volumio[11036]: *** WARNING *** For more information see Jan 28 16:58:49 volumio node[11036]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:49 volumio node[11036]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:49 volumio node[11036]: *** WARNING *** For more information see Jan 28 16:58:49 volumio node[11036]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:58:49 volumio node[11036]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:58:49 volumio node[11036]: *** WARNING *** For more information see Jan 28 16:58:49 volumio volumio[11036]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 16:58:49 volumio volumio[11036]: info: Discovery: Started advertising with name: Volumio Jan 28 16:58:49 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:58:49 volumio volumio[11036]: info: Loading plugin "spop"... Jan 28 16:58:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:50 volumio volumio[11036]: info: Loading plugin "ytcr"... Jan 28 16:58:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 16:58:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:51 volumio go-librespot[11124]: go-librespot daemon starting... Jan 28 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+07:00" level=debug msg="app state loaded" Jan 28 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+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 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+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 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+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 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+07:00" level=info msg="zeroconf server listening on port 38909" Jan 28 16:58:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+07:00" level=debug msg="obtained new client token: AACybjRClI/UF32364bb/y4W8+3qhEFjbKoan2Kp/RReEEMFRkx3TzcKygQL+kkuuO1UtVvqgRanaNboxMqjLITrUCEY23L9Az3sWZ3tqGNrybYuqrWcp8MAaljL5L09xBS/6kv9RCtx2Z7LDCc9fOyucBV6pI3AY6fW874Ju8gIORYUAgk/nAAiOggHNeeXpfE1JpBA2/qlSNuMM35SsNXtfoycT6+O6bzwQJ9EGC9PInM9ennMJQ1nYXw=" Jan 28 16:58:51 volumio go-librespot[11125]: time="2026-01-28T16:58:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:52 volumio go-librespot[11125]: time="2026-01-28T16:58:52+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:52 volumio go-librespot[11125]: time="2026-01-28T16:58:52+07:00" level=debug msg="completed challenge" Jan 28 16:58:52 volumio go-librespot[11125]: time="2026-01-28T16:58:52+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 16:58:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:53 volumio volumio[11036]: info: Loading plugin "ytmusic"... Jan 28 16:58:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:54 volumio volumio-remote-updater[628]: [2026-01-28 16:58:54] [connect] Successful connection Jan 28 16:58:54 volumio volumio[11036]: info: Loading plugin "outputs"... Jan 28 16:58:54 volumio volumio[11036]: info: Loading plugin "albumart"... Jan 28 16:58:54 volumio volumio[11036]: info: Plugin example_plugin is not enabled Jan 28 16:58:54 volumio volumio[11036]: info: Loading plugin "inputs"... Jan 28 16:58:54 volumio volumio[11036]: info: Loading plugin "updater_comm"... Jan 28 16:58:54 volumio volumio[11036]: info: Plugin mpdemulation is not enabled Jan 28 16:58:54 volumio volumio[11036]: info: Loading plugin "rest_api"... Jan 28 16:58:54 volumio volumio[11036]: info: Loading plugin "websocket"... Jan 28 16:58:55 volumio volumio[11036]: info: Starting Socket.io Server version 1.7.4 Jan 28 16:58:55 volumio volumio[11036]: info: Loading plugin "RoonBridge"... Jan 28 16:58:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 16:58:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:55 volumio go-librespot[11156]: go-librespot daemon starting... Jan 28 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+07:00" level=debug msg="app state loaded" Jan 28 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:58:55 volumio volumio[11036]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 16:58:55 volumio volumio[11036]: info: Loading i18n strings for locale en Jan 28 16:58:55 volumio volumio[11036]: Updating browse sources language Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+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 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+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 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+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 16:58:55 volumio volumio[11146]: Forking 3 albumart workers Jan 28 16:58:55 volumio go-librespot[11157]: time="2026-01-28T16:58:55+07:00" level=info msg="zeroconf server listening on port 40755" Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::initPlayerControls Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:58:55 volumio volumio[11036]: Express server listening on port 3000 Jan 28 16:58:55 volumio volumio[11036]: [Metrics] WebUI: 16s 178.72ms Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::resetVolumioState Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::getcurrentVolume Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:58:56 volumio go-librespot[11157]: time="2026-01-28T16:58:56+07:00" level=debug msg="obtained new client token: AABnEDM4dHLGre84o1z+pqT0R1KIy1CXmrDgoTPH4kXeGCeAcHdrijAsQoXEio3z+vXj3Da7Lwa3R8gfGZAMQ8CgKM669FITe5eZZSSmJhPgSisxDW+GO/8wqranKWIYDblhSPxPy+OaRzONvtnH45U0uxIbXdsgt/k/1DhEcAmwZPIx7pmHX7xLtJ8GJX+g5pUWvjWB21pKoEWnejKEpD53yiw16reT1uKbFDwocilw3MM0I1sJC4rv" Jan 28 16:58:56 volumio sudo[11198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:58:56 volumio sudo[11198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:56 volumio sudo[11198]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:56 volumio go-librespot[11157]: time="2026-01-28T16:58:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:58:56 volumio sudo[11196]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:58:56 volumio sudo[11196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:56 volumio sudo[11196]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:56 volumio volumio[11036]: info: Volumio Network Manager: Network status updated: 1 Jan 28 16:58:56 volumio go-librespot[11157]: time="2026-01-28T16:58:56+07:00" level=debug msg="completed keyexchange" Jan 28 16:58:56 volumio go-librespot[11157]: time="2026-01-28T16:58:56+07:00" level=debug msg="completed challenge" Jan 28 16:58:56 volumio go-librespot[11157]: time="2026-01-28T16:58:56+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 16:58:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:58:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:58:56 volumio volumio[11036]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::pushState Jan 28 16:58:56 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::updateTrackBlock Jan 28 16:58:56 volumio volumio[11036]: info: CorePlayQueue::getTrackBlock Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:58:56 volumio volumio-remote-updater[628]: [2026-01-28 16:58:56] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769594334 101 Jan 28 16:58:56 volumio volumio[11036]: 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 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:56 volumio volumio[11036]: info: Reloading queue from file Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::setRepeat null single undefined Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::pushState Jan 28 16:58:56 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::setRandom null Jan 28 16:58:56 volumio volumio[11036]: info: CoreStateMachine::pushState Jan 28 16:58:56 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:56 volumio volumio[11036]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:56 volumio volumio[11036]: info: Setting Device type: Raspberry PI Jan 28 16:58:57 volumio volumio[11036]: info: Completed loading Core Plugins Jan 28 16:58:57 volumio volumio[11036]: info: Preparing to generate the ALSA configuration file Jan 28 16:58:57 volumio volumio[11036]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:58:57 volumio volumio[11036]: info: CoreStateMachine::pushState Jan 28 16:58:57 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::volumioPushState Jan 28 16:58:57 volumio volumio[11036]: info: Asound.conf file unchanged, so no further update is needed Jan 28 16:58:57 volumio volumio[11036]: info: Output device has changed, restarting MPD Jan 28 16:58:57 volumio sudo[11214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 16:58:57 volumio sudo[11214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:57 volumio volumio[11036]: info: Output device has changed, restarting Shairport Sync Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:57 volumio sudo[11216]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:58:57 volumio sudo[11216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:57 volumio sudo[11216]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:57 volumio sudo[11219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:58:57 volumio sudo[11219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:57 volumio sudo[11214]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:57 volumio volumio[11036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:58:57 volumio volumio[11036]: info: ___________ START PLUGINS ___________ Jan 28 16:58:57 volumio volumio[11036]: info: ControllerMpd::onStart: Initializing MPD Jan 28 16:58:57 volumio volumio[11036]: info: Creating MPD Configuration file Jan 28 16:58:57 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:57 volumio volumio[11036]: info: [1769594337580] CoreMusicLibrary::Adding element Media Servers Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:57 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:58:57 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:58:57 volumio systemd[1]: mpd.service: Consumed 7.451s CPU time. Jan 28 16:58:57 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:58:57 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:58:57 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:58:57 volumio sudo[11227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:58:57 volumio sudo[11227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:57 volumio volumio[11036]: info: UPNP Browser: Client initialized successfully Jan 28 16:58:57 volumio sudo[11229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:58:57 volumio sudo[11227]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:57 volumio sudo[11229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:58:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:57 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:58:57 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:58:57 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:58:57 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:58:57 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:58:57 volumio volumio[11036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:57 volumio volumio[11036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:57 volumio volumio[11036]: info: [1769594337891] CoreMusicLibrary::Adding element Last_100 Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:57 volumio volumio[11036]: info: [1769594337903] CoreMusicLibrary::Adding element Webradio Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:57 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:58:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:58:57 volumio volumio[11036]: info: Initializing BBC Radios Jan 28 16:58:58 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:58:58 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:58:58 volumio volumio[11036]: info: Creating Spotify config file Jan 28 16:58:58 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:58:58 volumio sudo[11243]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 16:58:58 volumio sudo[11243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 16:58:58 volumio sudo[11243]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:59 volumio volumio[11165]: Starting albumart workers Jan 28 16:58:59 volumio volumio[11036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:58:59 volumio volumio[11036]: info: [1769594339231] CoreMusicLibrary::Adding element YouTube Music Jan 28 16:58:59 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:58:59 volumio volumio[11036]: Cannot find translation for source YouTube Music Jan 28 16:58:59 volumio volumio[11166]: Starting albumart workers Jan 28 16:58:59 volumio volumio[11164]: Starting albumart workers Jan 28 16:58:59 volumio volumio[11036]: info: Volumio Calling Home Jan 28 16:58:59 volumio sudo[11260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 16:58:59 volumio sudo[11260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:58:59 volumio sudo[11260]: pam_unix(sudo:session): session closed for user root Jan 28 16:58:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 16:58:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:58:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:58:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:58:59 volumio go-librespot[11265]: go-librespot daemon starting... Jan 28 16:58:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:58:59 volumio go-librespot[11266]: time="2026-01-28T16:58:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:00 volumio volumio[11036]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:59:00 volumio volumio[11036]: info: Discovery: Found device Volumio Jan 28 16:59:00 volumio volumio[11036]: info: CoreCommandRouter::volumioGetState Jan 28 16:59:00 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:59:00 volumio volumio[11036]: info: MPD Permissions set Jan 28 16:59:00 volumio volumio[11036]: info: MPD Permissions set Jan 28 16:59:00 volumio volumio[11036]: info: Upmpdcli Daemon Started Jan 28 16:59:00 volumio volumio[11036]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:59:00 volumio volumio[11036]: info: Discovery: Found device Volumio Jan 28 16:59:00 volumio volumio[11036]: info: CoreCommandRouter::volumioGetState Jan 28 16:59:00 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:59:00 volumio volumio[11036]: info: Volumio called home Jan 28 16:59:00 volumio volumio[11036]: info: Spotify config file written Jan 28 16:59:00 volumio sudo[11276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 16:59:00 volumio sudo[11276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:00 volumio go-librespot[11266]: time="2026-01-28T16:59:00+07:00" level=info msg="zeroconf server listening on port 43207" Jan 28 16:59:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 16:59:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 16:59:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:00 volumio go-librespot[11278]: go-librespot daemon starting... Jan 28 16:59:00 volumio sudo[11276]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:01 volumio volumio[11036]: 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 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59:01+07:00" level=debug msg="app state loaded" Jan 28 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:59:01 volumio volumio[11036]: info: No need to fix Spotify hosts Jan 28 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59: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-gew4.spotify.com:80]" Jan 28 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59:01+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 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59:01+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 16:59:01 volumio go-librespot[11279]: time="2026-01-28T16:59:01+07:00" level=info msg="zeroconf server listening on port 43771" Jan 28 16:59:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:02 volumio go-librespot[11279]: time="2026-01-28T16:59:02+07:00" level=debug msg="obtained new client token: AAA2IelCSDE0Vt9xUjOKiIStIg0u47Vzm+TmAlPLlC/8KDDtcCkDxim95Lm1CBNEgc3jZYDtHNBu7gYlRpPpEmaRsB77QfSgcrcSunJB7SLMK/PQzGBi0ymVXzA/vW++PKYgzMrndNQGelde8vl6Pmd98kgA4it8zd50ti7264XeYZ/OxqlWVd2Ok/jtOW8Ej1OftGPE6gn0JiD3KczZIhrdnoOoDf3pto8ZjpCJ5GkbkYFkXw08VnV4" Jan 28 16:59:02 volumio go-librespot[11279]: time="2026-01-28T16:59:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:59:02 volumio volumio[11036]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:59:02 volumio volumio[11036]: SPOTIFY: BQDpiN5KMkg1gsuiuM5jUr7IB-rT87OoHTMYZr_ei7-o25NdxEUEhd9mIqiHN3VLsBVq-DjzkDR9NkZD25RulsplcG8bUwcvW_uLP9cDWsQHYY3tRZH2Emge4mlrTH4WO98cmar7VL_tNscdmPkF8OXowE6LwkC_KgLWicGvoXTK_pMj7uEHnjHlOJPjhOjCCAHBb3qpbFncKbgfPkeY3ajpj_3THWjMOP5y5h3ixnAYPZ2O-lfh8JawZN8aYAA7lIGmFYt6Wiywcaw5kN2YuCfG5wCWyMco4FpX_U89JrAoo9Wy5jVvbA7w Jan 28 16:59:02 volumio volumio[11036]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:59:02 volumio volumio[11036]: info: New Spotify access token = BQDpiN5KMkg1gsuiuM5jUr7IB-rT87OoHTMYZr_ei7-o25NdxEUEhd9mIqiHN3VLsBVq-DjzkDR9NkZD25RulsplcG8bUwcvW_uLP9cDWsQHYY3tRZH2Emge4mlrTH4WO98cmar7VL_tNscdmPkF8OXowE6LwkC_KgLWicGvoXTK_pMj7uEHnjHlOJPjhOjCCAHBb3qpbFncKbgfPkeY3ajpj_3THWjMOP5y5h3ixnAYPZ2O-lfh8JawZN8aYAA7lIGmFYt6Wiywcaw5kN2YuCfG5wCWyMco4FpX_U89JrAoo9Wy5jVvbA7w Jan 28 16:59:02 volumio volumio[11036]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 16:59:02 volumio go-librespot[11279]: time="2026-01-28T16:59:02+07:00" level=debug msg="completed keyexchange" Jan 28 16:59:02 volumio go-librespot[11279]: time="2026-01-28T16:59:02+07:00" level=debug msg="completed challenge" Jan 28 16:59:02 volumio go-librespot[11279]: time="2026-01-28T16:59: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 16:59:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:59:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:59:02 volumio volumio[11036]: info: Starting Shairport Sync Jan 28 16:59:02 volumio volumio[11036]: info: Starting Shairport Sync Jan 28 16:59:02 volumio volumio[11036]: info: Starting Shairport Sync Jan 28 16:59:02 volumio sudo[11315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:59:02 volumio sudo[11315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:02 volumio sudo[11317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:59:02 volumio sudo[11317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:02 volumio sudo[11319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:59:02 volumio sudo[11319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 16:59:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 16:59:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:59:02 volumio systemd[1]: shairport-sync.service: Consumed 2.329s CPU time. Jan 28 16:59:02 volumio volumio[11036]: info: CoreCommandRouter::volumioGetState Jan 28 16:59:02 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:59:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:59:02 volumio sudo[11315]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:02 volumio sudo[11317]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:02 volumio volumio[11036]: info: Shairport-Sync Started Jan 28 16:59:02 volumio volumio[11036]: Error adding Membership: Error: addMembership EINVAL Jan 28 16:59:02 volumio sudo[11319]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:02 volumio volumio[11036]: info: Shairport-Sync Started Jan 28 16:59:02 volumio volumio[11036]: info: Shairport-Sync Started Jan 28 16:59:02 volumio volumio[11036]: 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 16:59:02 volumio volumio[11036]: info: Spotify Successfully logged in Jan 28 16:59:03 volumio volumio[11036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:59:03 volumio volumio[11036]: info: [1769594343011] CoreMusicLibrary::Adding element Spotify Jan 28 16:59:03 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:59:03 volumio volumio[11036]: Cannot find translation for source YouTube Music Jan 28 16:59:03 volumio volumio[11036]: Cannot find translation for source Spotify Jan 28 16:59:03 volumio volumio[11036]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 16:59:03 volumio volumio[11036]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:59:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:03 volumio volumio[11036]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:59:03 volumio volumio[11036]: info: CoreCommandRouter::volumioGetState Jan 28 16:59:03 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:59:03 volumio volumio[11036]: info: CoreStateMachine::pushState Jan 28 16:59:03 volumio volumio[11036]: info: CorePlayQueue::getTrack 0 Jan 28 16:59:03 volumio volumio[11036]: info: CoreCommandRouter::volumioPushState Jan 28 16:59:04 volumio volumio[11036]: info: go-librespot daemon successfully initialized Jan 28 16:59:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 16:59:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:05 volumio go-librespot[11355]: go-librespot daemon starting... Jan 28 16:59:05 volumio go-librespot[11356]: time="2026-01-28T16:59:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:05 volumio go-librespot[11356]: time="2026-01-28T16:59:05+07:00" level=debug msg="app state loaded" Jan 28 16:59:05 volumio go-librespot[11356]: time="2026-01-28T16:59:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:59:05 volumio mpd[11258]: 2026-01-28T16:59:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 16:59:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 16:59:05 volumio sudo[11219]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:05 volumio sudo[11229]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:06 volumio volumio[11036]: error: MPD error: The expression evaluated to a falsy value: Jan 28 16:59:06 volumio volumio[11036]: assert.ok(self.idling) Jan 28 16:59:06 volumio volumio[11036]: error: The expression evaluated to a falsy value: Jan 28 16:59:06 volumio volumio[11036]: assert.ok(self.idling) Jan 28 16:59:06 volumio volumio[11036]: error: updateQueue error: null Jan 28 16:59:06 volumio volumio[11036]: info: MPD running with PID11258 Jan 28 16:59:06 volumio volumio[11036]: ,establishing connection Jan 28 16:59:06 volumio volumio[11036]: info: Completed starting Core Plugins Jan 28 16:59:06 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:59:06 volumio volumio[11036]: info: ----- MyVolumio plugins startup ---- Jan 28 16:59:06 volumio volumio[11036]: info: ------------------------------------------- Jan 28 16:59:06 volumio volumio[11036]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+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 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+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 16:59:06 volumio volumio[11036]: error: updateQueue error: null Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+07:00" level=info msg="zeroconf server listening on port 45157" Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+07:00" level=debug msg="obtained new client token: AABF25rbl4uol23g/f5DpDEAnFO4axKTaXOBoO6a6NCEf2JgMlrQr3C//44I/eQzTsqJNbK6m2GarMuLGY5LtwxFF34jqAvReJJhhUMc6m0mt8eWsd2bH1p0rMTj+/Yiy8Pq/sm6+v+Co/CDDTgTsp2yaX1q7aSPxfyxORCN3EVqnPjB5e2T13UcfdkMNmaIrfcCEnERW613aBh3BZuADzaoP1nZul05q0Zmfa3JHCIc1Nzf+lY2WZzfY40=" Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+07:00" level=debug msg="completed keyexchange" Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59:06+07:00" level=debug msg="completed challenge" Jan 28 16:59:06 volumio go-librespot[11356]: time="2026-01-28T16:59: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 16:59:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:59:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:59:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:07 volumio volumio[11036]: info: Initializing connection to go-librespot Websocket Jan 28 16:59:07 volumio volumio[11036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:59:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 16:59:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:09 volumio go-librespot[11369]: go-librespot daemon starting... Jan 28 16:59:09 volumio go-librespot[11370]: time="2026-01-28T16:59:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:09 volumio go-librespot[11370]: time="2026-01-28T16:59:09+07:00" level=debug msg="app state loaded" Jan 28 16:59:09 volumio go-librespot[11370]: time="2026-01-28T16:59:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:59:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+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 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+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 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+07:00" level=info msg="zeroconf server listening on port 39495" Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+07:00" level=debug msg="obtained new client token: AAD9bIPf+JdKbdqMr8nnrQTUwmfn3hm2Y3nvjEJaPoXDPO8ThMVBoemO6/QC6en6a2yX81i/8NUU3xN1MaRDNysdbkpS8x5/84xu3BJZkAc7XzEecM2PrqVztxpLC1OvxUT3Dax/shVk1oIhPqwC6et2PQ/0nMcxWxE1VwoaD5WQfKEjE1nskMKepU2D2gnZ4uR8SDLNBJ4zCiakQ+K70BwoEphjtvZhPN7Xu2PGWaUQUtxj4gzPZ3coKM0=" Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+07:00" level=debug msg="completed keyexchange" Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59:10+07:00" level=debug msg="completed challenge" Jan 28 16:59:10 volumio go-librespot[11370]: time="2026-01-28T16:59: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 16:59:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:59:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:59:10 volumio volumio[11036]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 16:59:10 volumio volumio[11036]: info: Initializing connection to go-librespot Websocket Jan 28 16:59:11 volumio volumio[11036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:59:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 16:59:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:14 volumio volumio[11036]: info: Initializing connection to go-librespot Websocket Jan 28 16:59:14 volumio volumio[11036]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:59:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:14 volumio go-librespot[11377]: go-librespot daemon starting... Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=debug msg="app state loaded" Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+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 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+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 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=info msg="zeroconf server listening on port 34439" Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=debug msg="obtained new client token: AACEzpe4bIQp9KprFoz62BHpJw8Sa39btZ1ln3yP7afaw/RaC00mXEsv+UYIzZozeYSxoL4FtmGvUKZ+nNBKH5KKIi2MKDU/hNQfYvKmhfDl33hOR3ejPRgvEGi/c6yzYRtHPANspUliKcH2RpOnskB1tlzxWiRhZ4zj96LDptapnsATz0LKlbHyxt3ItsNKjuxdsNOBZduhnX3K94ePU5dGMSawZ6zpBUw/i4TmRfnmlntrrN0Qa/dXTME=" Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 16:59:14 volumio volumio[11036]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:59:14 volumio go-librespot[11378]: time="2026-01-28T16:59:14+07:00" level=debug msg="completed keyexchange" Jan 28 16:59:15 volumio go-librespot[11378]: time="2026-01-28T16:59:15+07:00" level=debug msg="completed challenge" Jan 28 16:59:15 volumio go-librespot[11378]: time="2026-01-28T16:59: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 16:59:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:59:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:59:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:16 volumio volumio[11036]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 16:59:16 volumio volumio[11036]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 16:59:16 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:16 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:16 volumio volumio[11036]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 16:59:16 volumio volumio[11036]: info: MyVolumio login type: Token Jan 28 16:59:16 volumio volumio[11036]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 16:59:16 volumio volumio[11036]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 16:59:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 16:59:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:18 volumio go-librespot[11399]: go-librespot daemon starting... Jan 28 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+07:00" level=debug msg="app state loaded" Jan 28 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:59:18 volumio volumio[11036]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 16:59:18 volumio volumio[11036]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 16:59:18 volumio volumio[11036]: info: Streaming services startup Jan 28 16:59:18 volumio volumio[11036]: info: Starting Streaming Daemon Jan 28 16:59:18 volumio volumio[11036]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 16:59:18 volumio sudo[11407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 16:59:18 volumio sudo[11407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:18 volumio sudo[11407]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:18 volumio volumio[11036]: info: Initializing connection to go-librespot Websocket Jan 28 16:59:18 volumio volumio[11036]: error: Cannot start Volumio Streaming Daemon Jan 28 16:59:18 volumio volumio[11036]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 16:59:18 volumio volumio[11036]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+07:00" level=debug msg="new websocket client" Jan 28 16:59:18 volumio volumio[11036]: info: Connection to go-librespot Websocket established Jan 28 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+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 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+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 16:59:18 volumio go-librespot[11400]: time="2026-01-28T16:59:18+07:00" level=info msg="zeroconf server listening on port 46585" Jan 28 16:59:19 volumio go-librespot[11400]: time="2026-01-28T16:59:19+07:00" level=debug msg="obtained new client token: AACRPzdT17mLkii7mXImW5dyAbbwpOBJHTWBxzV2OQVdAJ+GtycAw64N2tbNDvws1XOiQfY2XgT9zXf8GP3IMEbRnRrujj9/AkX9i5LvIG50aVoykie/MtP84Wj7ZPw24E/CKzsAFfZisr39ewM9iRogkt4jC/IkQuscy7b6Bn5g3IO/xzHqpv4CWisbL8qwFALfCc6bMLkSgjMYKX+Zzik1eCvWkbQvtClcEAaOCRA8FhikBphDNgYW" Jan 28 16:59:19 volumio go-librespot[11400]: time="2026-01-28T16:59:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:59:19 volumio go-librespot[11400]: time="2026-01-28T16:59:19+07:00" level=debug msg="completed keyexchange" Jan 28 16:59:19 volumio go-librespot[11400]: time="2026-01-28T16:59:19+07:00" level=debug msg="completed challenge" Jan 28 16:59:19 volumio go-librespot[11400]: time="2026-01-28T16:59: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 16:59:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:59:19 volumio volumio[11036]: info: Connection to go-librespot Websocket closed Jan 28 16:59:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:59:19 volumio volumio[11036]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 16:59:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:20 volumio volumio[11036]: info: MyVolumio token set successfully Jan 28 16:59:20 volumio volumio[11036]: info: MYVOLUMIO: Adding device Jan 28 16:59:20 volumio volumio[11036]: info: MYVOLUMIO: Evaluating Server Jan 28 16:59:20 volumio volumio[11036]: info: MyVolumio status changed Jan 28 16:59:20 volumio volumio[11036]: info: Streaming services startup Jan 28 16:59:20 volumio volumio[11036]: info: Starting Streaming Daemon Jan 28 16:59:20 volumio volumio[11036]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 16:59:20 volumio volumio[11036]: info: Removing audio output: Jan 28 16:59:20 volumio volumio[11036]: info: Stoppping Tunnel 1 Jan 28 16:59:20 volumio sudo[11436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 16:59:20 volumio sudo[11436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:21 volumio sudo[11436]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:21 volumio sudo[11439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 16:59:21 volumio sudo[11439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:21 volumio volumio[11036]: error: Cannot start Volumio Streaming Daemon Jan 28 16:59:21 volumio volumio[11036]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 16:59:21 volumio volumio[11036]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 16:59:21 volumio sudo[11439]: pam_unix(sudo:session): session closed for user root Jan 28 16:59:21 volumio volumio[11036]: info: Remote SSH Stopped Jan 28 16:59:21 volumio volumio[11036]: info: Setting Geolocation for MyVolumio to as1 Jan 28 16:59:21 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:21 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:21 volumio volumio[11036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:59:21 volumio volumio[11036]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 16:59:21 volumio volumio[11036]: info: Getting Spotify volume Jan 28 16:59:21 volumio volumio[11036]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:59:21 volumio volumio[11036]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:59:21 volumio volumio[11036]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 16:59:21 volumio volumio[11036]: errno: -111, Jan 28 16:59:21 volumio volumio[11036]: code: 'ECONNREFUSED', Jan 28 16:59:21 volumio volumio[11036]: syscall: 'connect', Jan 28 16:59:21 volumio volumio[11036]: address: '127.0.0.1', Jan 28 16:59:21 volumio volumio[11036]: port: 9879, Jan 28 16:59:21 volumio volumio[11036]: response: undefined Jan 28 16:59:21 volumio volumio[11036]: } Jan 28 16:59:21 volumio volumio[11036]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:59:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:59:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:59:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:59:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 16:59:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:59:22 volumio go-librespot[11453]: go-librespot daemon starting... Jan 28 16:59:22 volumio go-librespot[11454]: time="2026-01-28T16:59:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:59:22 volumio go-librespot[11454]: time="2026-01-28T16:59:22+07:00" level=debug msg="app state loaded" Jan 28 16:59:22 volumio go-librespot[11454]: time="2026-01-28T16:59:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:59:23 volumio sudo[11464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 16:58' Jan 28 16:59:23 volumio sudo[11464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:59:23 volumio go-librespot[11454]: time="2026-01-28T16:59: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:59:23 volumio go-librespot[11454]: time="2026-01-28T16:59:23+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 16:59:23 volumio go-librespot[11454]: time="2026-01-28T16:59:23+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 16:59:23 volumio go-librespot[11454]: time="2026-01-28T16:59:23+07:00" level=info msg="zeroconf server listening on port 43545" 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"