Jan 27 02:57:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:00 volumio go-librespot[25662]: go-librespot daemon starting... Jan 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+07:00" level=debug msg="app state loaded" Jan 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+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 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+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 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+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 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+07:00" level=info msg="zeroconf server listening on port 43939" Jan 27 02:57:00 volumio go-librespot[25663]: time="2026-01-27T02:57:00+07:00" level=debug msg="obtained new client token: AABZ1Alzkh7SKSRyI3hFVaXt3eBONFWXcMEfG71XNrWBPv0PgMED9lzYfiYsYW9EtApBppr9MKLU4g8XjWe8skXprayhrfceGbi+t+YEc1AbFRt1spXVa3p20W0sCW129SmVNq3xJIO2zm8UMFbMKDJk+P0/KJpMo0LkbWRdMm5ek4PB6raThHBMJtz2uoYEkUc+h6O+4D4Pb/OAImXJzqjex0SOb5Uo1O2BJuRivmEHjeh7fOCA8RmNgJ0=" Jan 27 02:57:01 volumio go-librespot[25663]: time="2026-01-27T02:57:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:01 volumio go-librespot[25663]: time="2026-01-27T02:57:01+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:01 volumio go-librespot[25663]: time="2026-01-27T02:57:01+07:00" level=debug msg="completed challenge" Jan 27 02:57:01 volumio go-librespot[25663]: time="2026-01-27T02:57:01+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 27 02:57:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:01 volumio volumio[25573]: info: Loading plugin "ytmusic"... Jan 27 02:57:02 volumio volumio-remote-updater[628]: [2026-01-27 02:57:02] [connect] Successful connection Jan 27 02:57:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "outputs"... Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "albumart"... Jan 27 02:57:02 volumio volumio[25573]: info: Plugin example_plugin is not enabled Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "inputs"... Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "updater_comm"... Jan 27 02:57:02 volumio volumio[25573]: info: Plugin mpdemulation is not enabled Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "rest_api"... Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "websocket"... Jan 27 02:57:02 volumio volumio[25573]: info: Starting Socket.io Server version 1.7.4 Jan 27 02:57:02 volumio volumio[25573]: info: Loading plugin "RoonBridge"... Jan 27 02:57:03 volumio volumio[25573]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 02:57:03 volumio volumio[25573]: info: Loading i18n strings for locale en Jan 27 02:57:03 volumio volumio[25573]: Updating browse sources language Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:03 volumio volumio[25686]: Forking 3 albumart workers Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::initPlayerControls Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:57:03 volumio volumio[25573]: Express server listening on port 3000 Jan 27 02:57:03 volumio volumio[25573]: [Metrics] WebUI: 16s 118.20ms Jan 27 02:57:03 volumio volumio[25573]: info: CoreStateMachine::resetVolumioState Jan 27 02:57:03 volumio volumio[25573]: info: CoreStateMachine::getcurrentVolume Jan 27 02:57:03 volumio volumio[25573]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:57:04 volumio sudo[25731]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 02:57:04 volumio sudo[25731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:04 volumio sudo[25731]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:04 volumio sudo[25733]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 02:57:04 volumio sudo[25733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:04 volumio sudo[25733]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:04 volumio volumio[25573]: info: Volumio Network Manager: Network status updated: 1 Jan 27 02:57:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:04 volumio volumio[25573]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:57:04 volumio volumio[25573]: info: CoreStateMachine::pushState Jan 27 02:57:04 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:04 volumio volumio[25573]: info: CoreStateMachine::updateTrackBlock Jan 27 02:57:04 volumio volumio[25573]: info: CorePlayQueue::getTrackBlock Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:57:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 02:57:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:04 volumio volumio-remote-updater[628]: [2026-01-27 02:57:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769457422 101 Jan 27 02:57:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:04 volumio go-librespot[25738]: go-librespot daemon starting... Jan 27 02:57:04 volumio volumio[25573]: 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 27 02:57:04 volumio go-librespot[25739]: time="2026-01-27T02:57:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:04 volumio go-librespot[25739]: time="2026-01-27T02:57:04+07:00" level=debug msg="app state loaded" Jan 27 02:57:04 volumio go-librespot[25739]: time="2026-01-27T02:57:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:04 volumio volumio[25573]: info: Reloading queue from file Jan 27 02:57:04 volumio volumio[25573]: info: CoreStateMachine::setRepeat null single undefined Jan 27 02:57:04 volumio volumio[25573]: info: CoreStateMachine::pushState Jan 27 02:57:04 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:04 volumio volumio[25573]: info: CoreStateMachine::setRandom null Jan 27 02:57:04 volumio volumio[25573]: info: CoreStateMachine::pushState Jan 27 02:57:04 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:04 volumio volumio[25573]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:04 volumio volumio[25573]: info: Setting Device type: Raspberry PI Jan 27 02:57:04 volumio volumio[25573]: info: Completed loading Core Plugins Jan 27 02:57:04 volumio volumio[25573]: info: Preparing to generate the ALSA configuration file Jan 27 02:57:05 volumio volumio[25573]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:57:05 volumio volumio[25573]: info: CoreStateMachine::pushState Jan 27 02:57:05 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:05 volumio volumio[25573]: info: Asound.conf file unchanged, so no further update is needed Jan 27 02:57:05 volumio volumio[25573]: info: Output device has changed, restarting MPD Jan 27 02:57:05 volumio sudo[25754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 02:57:05 volumio volumio[25573]: info: Output device has changed, restarting Shairport Sync Jan 27 02:57:05 volumio sudo[25754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:05 volumio sudo[25756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 02:57:05 volumio sudo[25756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:05 volumio sudo[25756]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+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 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+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 27 02:57:05 volumio volumio[25573]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:57:05 volumio volumio[25573]: info: ___________ START PLUGINS ___________ Jan 27 02:57:05 volumio sudo[25758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 02:57:05 volumio sudo[25758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+07:00" level=info msg="zeroconf server listening on port 41509" Jan 27 02:57:05 volumio volumio[25573]: info: ControllerMpd::onStart: Initializing MPD Jan 27 02:57:05 volumio volumio[25573]: info: Creating MPD Configuration file Jan 27 02:57:05 volumio sudo[25754]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:05 volumio sudo[25767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 02:57:05 volumio volumio[25573]: info: [1769457425504] CoreMusicLibrary::Adding element Media Servers Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:05 volumio sudo[25767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:05 volumio sudo[25767]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:05 volumio volumio[25573]: info: UPNP Browser: Client initialized successfully Jan 27 02:57:05 volumio sudo[25769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 02:57:05 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 02:57:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 02:57:05 volumio systemd[1]: mpd.service: Consumed 7.359s CPU time. Jan 27 02:57:05 volumio sudo[25769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 02:57:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 02:57:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+07:00" level=debug msg="obtained new client token: AAA0XiJwb8CPSEMVYrUsIdcOGLe1X3ZyaSKwWe7+cTCuNxOMx8XzXVfrqPiww2dgVA67cCD0s4T/iQUor+DnsR805cKmaKNop6xvjvztHrSeCoJIr+uqRD1jbB3lVI5Vnhh5uKS9Jmrfl12qekjiu7WsnDRpS+1p0oRHuo2ss4LyjppbkGV8IPWhLch2TPPStWDjR/eBh1+gbwGz3Oxj6xjoEu1aRgw6+ucFTOC0JvrpGWfxgseXfl74n8M=" Jan 27 02:57:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:05 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 02:57:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 02:57:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 02:57:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 02:57:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 02:57:05 volumio volumio[25573]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 02:57:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+07:00" level=debug msg="completed challenge" Jan 27 02:57:05 volumio volumio[25573]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:05 volumio volumio[25573]: info: [1769457425950] CoreMusicLibrary::Adding element Last_100 Jan 27 02:57:05 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:05 volumio go-librespot[25739]: time="2026-01-27T02:57:05+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 27 02:57:06 volumio volumio[25573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:06 volumio volumio[25573]: info: [1769457426011] CoreMusicLibrary::Adding element Webradio Jan 27 02:57:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:06 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:06 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:57:06 volumio volumio[25573]: info: Initializing BBC Radios Jan 27 02:57:06 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:57:06 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:06 volumio volumio[25573]: info: Creating Spotify config file Jan 27 02:57:06 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:06 volumio sudo[25783]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 02:57:06 volumio sudo[25783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 02:57:06 volumio sudo[25783]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:07 volumio volumio[25696]: Starting albumart workers Jan 27 02:57:07 volumio volumio[25698]: Starting albumart workers Jan 27 02:57:07 volumio volumio[25573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:07 volumio volumio[25573]: info: [1769457427224] CoreMusicLibrary::Adding element YouTube Music Jan 27 02:57:07 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:07 volumio volumio[25573]: Cannot find translation for source YouTube Music Jan 27 02:57:07 volumio volumio[25573]: info: Volumio Calling Home Jan 27 02:57:07 volumio sudo[25800]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 02:57:07 volumio sudo[25800]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:07 volumio sudo[25800]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:07 volumio volumio[25697]: Starting albumart workers Jan 27 02:57:08 volumio volumio[25573]: info: MPD Permissions set Jan 27 02:57:08 volumio volumio[25573]: info: MPD Permissions set Jan 27 02:57:08 volumio volumio[25573]: info: Upmpdcli Daemon Started Jan 27 02:57:08 volumio volumio[25573]: info: Spotify config file written Jan 27 02:57:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:08 volumio volumio[25573]: 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 27 02:57:08 volumio sudo[25806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 02:57:08 volumio sudo[25806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:08 volumio go-librespot[25815]: go-librespot daemon starting... Jan 27 02:57:08 volumio sudo[25806]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:08 volumio volumio[25573]: info: No need to fix Spotify hosts Jan 27 02:57:08 volumio go-librespot[25819]: time="2026-01-27T02:57:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:08 volumio go-librespot[25819]: time="2026-01-27T02:57:08+07:00" level=debug msg="app state loaded" Jan 27 02:57:08 volumio go-librespot[25819]: time="2026-01-27T02:57:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+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 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+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 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=info msg="zeroconf server listening on port 42497" Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=debug msg="obtained new client token: AACyW4qt1goo0WH6H+X7snfA/UaARkC22ewMXRy9VT7b4o/o99VIz2w7muuDYR0JUjcM1/rMrIfEvyN+ZYpuV4EMteRsalxQ/BQQnXkGkncGhWi8ElPJ436BOzcULmMy/Pe2hbupae3QB1LOwVvKGHwt2rTI3wYEJ6DWgvPGEsxrHOVXP3l3TJLCp1L0L8GuqvRnezY+BPo7HkkTOqpv4VLr0o+QB4hrxstogHk1qqgOpuqlgmscRejyYro=" Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=debug msg="completed challenge" Jan 27 02:57:09 volumio volumio[25573]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 02:57:09 volumio volumio[25573]: info: Discovery: Found device Volumio Jan 27 02:57:09 volumio volumio[25573]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:09 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:09 volumio volumio[25573]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 02:57:09 volumio volumio[25573]: info: Discovery: Found device Volumio Jan 27 02:57:09 volumio volumio[25573]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:09 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:09 volumio go-librespot[25819]: time="2026-01-27T02:57:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:10 volumio volumio[25573]: info: Volumio called home Jan 27 02:57:10 volumio volumio[25573]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 02:57:10 volumio volumio[25573]: SPOTIFY: BQAjr-S_zQvHNs9j3eACnuMT98KpkfkmeYtfQhTC_ty6S3euKzkR_C5kTNc3pxoekfNuv6YmoSRzYO_qzfeT6OrIcTQCu0axbUiopOLttMESkMrQtmbrFAkAweCm7nq7SRydw9dMc4Noqs3hDi4tIZywYR3u48p2EHR6rklby2ozzz8VZ_FYTrb02E7udPMYB5i7GCPRJQ09nwh1KoqailjhHmgC5OO1v0cGBHlDbXVIF6dUT7HT9gplk7QcltWka7AqAZ8uf79TjY7aYut6GIsU5MmrveEU-nwLGrAeEAcdQGclFVLuO43Q Jan 27 02:57:10 volumio volumio[25573]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 02:57:10 volumio volumio[25573]: info: New Spotify access token = BQAjr-S_zQvHNs9j3eACnuMT98KpkfkmeYtfQhTC_ty6S3euKzkR_C5kTNc3pxoekfNuv6YmoSRzYO_qzfeT6OrIcTQCu0axbUiopOLttMESkMrQtmbrFAkAweCm7nq7SRydw9dMc4Noqs3hDi4tIZywYR3u48p2EHR6rklby2ozzz8VZ_FYTrb02E7udPMYB5i7GCPRJQ09nwh1KoqailjhHmgC5OO1v0cGBHlDbXVIF6dUT7HT9gplk7QcltWka7AqAZ8uf79TjY7aYut6GIsU5MmrveEU-nwLGrAeEAcdQGclFVLuO43Q Jan 27 02:57:10 volumio volumio[25573]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 02:57:10 volumio volumio[25573]: info: Starting Shairport Sync Jan 27 02:57:10 volumio volumio[25573]: info: Starting Shairport Sync Jan 27 02:57:10 volumio volumio[25573]: info: Starting Shairport Sync Jan 27 02:57:10 volumio sudo[25848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:57:10 volumio sudo[25848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:10 volumio sudo[25850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:57:10 volumio sudo[25852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:57:10 volumio sudo[25850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:10 volumio sudo[25852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 02:57:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 02:57:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 02:57:10 volumio systemd[1]: shairport-sync.service: Consumed 2.333s CPU time. Jan 27 02:57:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 02:57:10 volumio sudo[25850]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:10 volumio sudo[25848]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:10 volumio sudo[25852]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:10 volumio volumio[25573]: info: Shairport-Sync Started Jan 27 02:57:10 volumio volumio[25573]: Error adding Membership: Error: addMembership EINVAL Jan 27 02:57:10 volumio volumio[25573]: info: Shairport-Sync Started Jan 27 02:57:10 volumio volumio[25573]: info: Shairport-Sync Started Jan 27 02:57:10 volumio volumio[25573]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:10 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:10 volumio volumio[25573]: 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 27 02:57:10 volumio volumio[25573]: info: Spotify Successfully logged in Jan 27 02:57:10 volumio volumio[25573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:10 volumio volumio[25573]: info: [1769457430969] CoreMusicLibrary::Adding element Spotify Jan 27 02:57:10 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:10 volumio volumio[25573]: Cannot find translation for source YouTube Music Jan 27 02:57:10 volumio volumio[25573]: Cannot find translation for source Spotify Jan 27 02:57:11 volumio volumio[25573]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 02:57:11 volumio volumio[25573]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:57:12 volumio volumio[25573]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:57:12 volumio volumio[25573]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:12 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:12 volumio volumio[25573]: info: CoreStateMachine::pushState Jan 27 02:57:12 volumio volumio[25573]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:12 volumio volumio[25573]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:13 volumio volumio[25573]: info: go-librespot daemon successfully initialized Jan 27 02:57:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 02:57:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:13 volumio go-librespot[25888]: go-librespot daemon starting... Jan 27 02:57:13 volumio go-librespot[25889]: time="2026-01-27T02:57:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:13 volumio go-librespot[25889]: time="2026-01-27T02:57:13+07:00" level=debug msg="app state loaded" Jan 27 02:57:13 volumio go-librespot[25889]: time="2026-01-27T02:57:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:13 volumio mpd[25798]: 2026-01-27T02:57:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 02:57:13 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 02:57:13 volumio sudo[25769]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:13 volumio sudo[25758]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:13 volumio volumio[25573]: error: MPD error: The expression evaluated to a falsy value: Jan 27 02:57:13 volumio volumio[25573]: assert.ok(self.idling) Jan 27 02:57:13 volumio volumio[25573]: error: The expression evaluated to a falsy value: Jan 27 02:57:13 volumio volumio[25573]: assert.ok(self.idling) Jan 27 02:57:13 volumio volumio[25573]: info: MPD running with PID25798 Jan 27 02:57:13 volumio volumio[25573]: ,establishing connection Jan 27 02:57:13 volumio volumio[25573]: error: updateQueue error: null Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+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 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+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 27 02:57:14 volumio volumio[25573]: info: Completed starting Core Plugins Jan 27 02:57:14 volumio volumio[25573]: info: ------------------------------------------- Jan 27 02:57:14 volumio volumio[25573]: info: ----- MyVolumio plugins startup ---- Jan 27 02:57:14 volumio volumio[25573]: info: ------------------------------------------- Jan 27 02:57:14 volumio volumio[25573]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+07:00" level=info msg="zeroconf server listening on port 39285" Jan 27 02:57:14 volumio volumio[25573]: error: updateQueue error: null Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+07:00" level=debug msg="obtained new client token: AAClQpGKeqCts+PJiBYr0JANlUmxDt4fjcpICjPaWtb7YMdMRMO5c1gN2lfDAND9w+MxCeTTwriaNC62vOFwYH65xeLGzxnEYVGWOkVZxwp5PH3CA0V75DETpMPmZZ76w8yFP/+Q6aaf8jQNnMTPBTu05EYFe5GSg7rNBKEr3AjS+GK4mID+Ehn/khaNGGNdziWK6a7hZcJ5f7Op1fQJ7JTBZ0E4mYRbtlMR50d5mUzpZUM8ufZ71Gli" Jan 27 02:57:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+07:00" level=debug msg="completed challenge" Jan 27 02:57:14 volumio go-librespot[25889]: time="2026-01-27T02:57:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:16 volumio volumio[25573]: info: Initializing connection to go-librespot Websocket Jan 27 02:57:16 volumio volumio[25573]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:57:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 27 02:57:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:17 volumio go-librespot[25900]: go-librespot daemon starting... Jan 27 02:57:17 volumio go-librespot[25901]: time="2026-01-27T02:57:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:17 volumio go-librespot[25901]: time="2026-01-27T02:57:17+07:00" level=debug msg="app state loaded" Jan 27 02:57:17 volumio go-librespot[25901]: time="2026-01-27T02:57:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+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 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+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 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+07:00" level=info msg="zeroconf server listening on port 39409" Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+07:00" level=debug msg="obtained new client token: AACJbhifX/SNmmykLqGB9wpqVnKxFCS2yiRLvmWkbf2Y+sFx9sd77udiqJ78un+jemfeST+tqH6K37si6Hiy+v4mA2Bo3yb08StiAmfG0YuQAwYGp6pt7EloimNXZXRhUpGJTq3Gz/TZwzFGwduB7U/wRs+GWJzigMZcUEIKW0dd3Q2aJwHJARX5k3CNuxxv7fmBN0Co0aYnolTmD2ZowaRQaPsduVnButizV2YF9tBpM4esH/mXiZZbuM0=" Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:18 volumio volumio[25573]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+07:00" level=debug msg="completed challenge" Jan 27 02:57:18 volumio go-librespot[25901]: time="2026-01-27T02:57:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:19 volumio volumio[25573]: info: Initializing connection to go-librespot Websocket Jan 27 02:57:19 volumio volumio[25573]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:57:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 27 02:57:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:22 volumio go-librespot[25910]: go-librespot daemon starting... Jan 27 02:57:22 volumio volumio[25573]: info: Initializing connection to go-librespot Websocket Jan 27 02:57:22 volumio volumio[25573]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+07:00" level=debug msg="app state loaded" Jan 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+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 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+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 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+07:00" level=info msg="zeroconf server listening on port 45243" Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 02:57:22 volumio volumio[25573]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 02:57:22 volumio go-librespot[25911]: time="2026-01-27T02:57:22+07:00" level=debug msg="obtained new client token: AACq9oGU/ECs62aqWgNPoDFGve0Xf0oalh8GZyPKWoRDC6OrTdkdwtnP4IOhx00rlIwQ/zbIKdptMxtblXpUSs3OL2tVU/eH9NsiUd+fb25RM8lcpjguZZxBTs9Nm+zZ2UELV1Z17TNaSyZCdZSeRlVZ/Qdvs+Z3tRUZ7HBD2VBzjddPFYkVPPjq/DeF6l8QhJfebQC8k4CHFadFYwW5NYj0aqvX0MXb+oHvxga/LNAqe7wiJtuOBu133CA=" Jan 27 02:57:23 volumio go-librespot[25911]: time="2026-01-27T02:57:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:23 volumio go-librespot[25911]: time="2026-01-27T02:57:23+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:23 volumio go-librespot[25911]: time="2026-01-27T02:57:23+07:00" level=debug msg="completed challenge" Jan 27 02:57:23 volumio go-librespot[25911]: time="2026-01-27T02:57:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:24 volumio volumio[25573]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 02:57:24 volumio volumio[25573]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 02:57:24 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:24 volumio volumio[25573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:24 volumio volumio[25573]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 02:57:24 volumio volumio[25573]: info: MyVolumio login type: Token Jan 27 02:57:24 volumio volumio[25573]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 02:57:24 volumio volumio[25573]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 02:57:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:26 volumio volumio[25573]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 02:57:26 volumio volumio[25573]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 02:57:26 volumio volumio[25573]: info: Streaming services startup Jan 27 02:57:26 volumio volumio[25573]: info: Starting Streaming Daemon Jan 27 02:57:26 volumio sudo[25934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 02:57:26 volumio sudo[25934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:26 volumio volumio[25573]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 02:57:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 27 02:57:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:26 volumio go-librespot[25940]: go-librespot daemon starting... Jan 27 02:57:26 volumio go-librespot[25941]: time="2026-01-27T02:57:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:26 volumio go-librespot[25941]: time="2026-01-27T02:57:26+07:00" level=debug msg="app state loaded" Jan 27 02:57:26 volumio go-librespot[25941]: time="2026-01-27T02:57:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:26 volumio sudo[25934]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:26 volumio volumio[25573]: info: Initializing connection to go-librespot Websocket Jan 27 02:57:26 volumio volumio[25573]: error: Cannot start Volumio Streaming Daemon Jan 27 02:57:26 volumio volumio[25573]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 02:57:26 volumio volumio[25573]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 02:57:26 volumio go-librespot[25941]: time="2026-01-27T02:57:26+07:00" level=debug msg="new websocket client" Jan 27 02:57:26 volumio volumio[25573]: info: Connection to go-librespot Websocket established Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+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 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+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 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+07:00" level=info msg="zeroconf server listening on port 36259" Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+07:00" level=debug msg="obtained new client token: AAD1Gu4P02S8W9KeqpovfL+eQPJ4ExsFe1CHLOv2NnvUncR8tg3wc7sc7npHSmxoh/2m6zyBmwJWBGhqi1cYeP1H+rfi7aR+dhce8A5aDkA5ONFNhSE4irNiUnO8kG383VzqzaiaW/2SBQnxlB8hTYv5rKkvIjIve39vbCD8hKQ8dE90apYndIsB3qIQvvSmrRjig/Q0k3elNtoqu+4bvtaIcdmdNL4BjZjwvhlsO/6dlxhxAPkx6nvdtOE=" Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+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 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 02:57:27 volumio volumio[25573]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+07:00" level=debug msg="completed challenge" Jan 27 02:57:27 volumio go-librespot[25941]: time="2026-01-27T02:57:27+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 27 02:57:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:27 volumio volumio[25573]: info: Connection to go-librespot Websocket closed Jan 27 02:57:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:28 volumio volumio[25573]: info: MyVolumio token set successfully Jan 27 02:57:28 volumio volumio[25573]: info: MYVOLUMIO: Adding device Jan 27 02:57:28 volumio volumio[25573]: info: MYVOLUMIO: Evaluating Server Jan 27 02:57:29 volumio volumio[25573]: info: MyVolumio status changed Jan 27 02:57:29 volumio volumio[25573]: info: Streaming services startup Jan 27 02:57:29 volumio volumio[25573]: info: Starting Streaming Daemon Jan 27 02:57:29 volumio volumio[25573]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 02:57:29 volumio volumio[25573]: info: Removing audio output: Jan 27 02:57:29 volumio volumio[25573]: info: Stoppping Tunnel 1 Jan 27 02:57:29 volumio sudo[25970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 02:57:29 volumio sudo[25970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:29 volumio sudo[25972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 02:57:29 volumio sudo[25972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:29 volumio sudo[25970]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:29 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 27 02:57:29 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 27 02:57:29 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 27 02:57:29 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 27 02:57:29 volumio volumio[25573]: error: Cannot start Volumio Streaming Daemon Jan 27 02:57:29 volumio volumio[25573]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 02:57:29 volumio volumio[25573]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 02:57:29 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 27 02:57:29 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 27 02:57:29 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 27 02:57:29 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 27 02:57:29 volumio sudo[25972]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:29 volumio volumio[25573]: info: Remote SSH Stopped Jan 27 02:57:29 volumio volumio[25573]: info: Getting Spotify volume Jan 27 02:57:29 volumio volumio[25573]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 02:57:29 volumio volumio[25573]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:57:29 volumio volumio[25573]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 02:57:29 volumio volumio[25573]: errno: -111, Jan 27 02:57:29 volumio volumio[25573]: code: 'ECONNREFUSED', Jan 27 02:57:29 volumio volumio[25573]: syscall: 'connect', Jan 27 02:57:29 volumio volumio[25573]: address: '127.0.0.1', Jan 27 02:57:29 volumio volumio[25573]: port: 9879, Jan 27 02:57:29 volumio volumio[25573]: response: undefined Jan 27 02:57:29 volumio volumio[25573]: } Jan 27 02:57:29 volumio volumio[25573]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 02:57:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 27 02:57:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:31 volumio go-librespot[25987]: go-librespot daemon starting... Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=debug msg="app state loaded" Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:31 volumio sudo[25996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 02:56' Jan 27 02:57:31 volumio sudo[25996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:31 volumio sudo[25996]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+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 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+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 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=info msg="zeroconf server listening on port 41121" Jan 27 02:57:31 volumio volumio-remote-updater[628]: [2026-01-27 02:57:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 02:57:31 volumio volumio-remote-updater[628]: [2026-01-27 02:57:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 02:57:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 02:57:31 volumio systemd[1]: volumio.service: Consumed 1min 13.943s CPU time. Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=debug msg="obtained new client token: AAAmRag8yo5mbPrc//kPQ5lkPz6+UlgZ029YGxVYdiqM2torWpt2MqDxRuLVcK79Mtc+D/jAMrgCP3r7TpSLCEXDv6pbeHoeM1qsLBxipV2oNPuqaI+2w425Q48poP9Qeb99s/3WWaflSW7yqlF9JyO46vQCEGAnHT8Jzc/gL0wO1cjFjdTypjcuW4IC0MsO6w0xcQ3Kkk2m8oN+HQ/OnGfwlRQ/KLZEoE53ypi8hdiUJlChjwacD4Cc8t8=" Jan 27 02:57:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 02:57:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 02:57:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7905. Jan 27 02:57:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 02:57:31 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 02:57:31 volumio systemd[1]: volumio.service: Consumed 1min 13.943s CPU time. Jan 27 02:57:31 volumio go-librespot[25988]: time="2026-01-27T02:57:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:31 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 02:57:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 02:57:32 volumio go-librespot[25988]: time="2026-01-27T02:57:32+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:32 volumio go-librespot[25988]: time="2026-01-27T02:57:32+07:00" level=debug msg="completed challenge" Jan 27 02:57:32 volumio go-librespot[25988]: time="2026-01-27T02:57:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 27 02:57:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:35 volumio go-librespot[26024]: go-librespot daemon starting... Jan 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+07:00" level=debug msg="app state loaded" Jan 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:35 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:57:35 volumio volumio[26009]: info: ----- Volumio3 ---- Jan 27 02:57:35 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:57:35 volumio volumio[26009]: info: ----- System startup ---- Jan 27 02:57:35 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+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 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+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 27 02:57:35 volumio go-librespot[26031]: time="2026-01-27T02:57:35+07:00" level=info msg="zeroconf server listening on port 41147" Jan 27 02:57:36 volumio go-librespot[26031]: time="2026-01-27T02:57:36+07:00" level=debug msg="obtained new client token: AACGJ84RdCBlq6uw2YYclWERMOPrdwB7Wo2aH1ZMTSchsYqk6fOWFL829xVSqDBgSQxa9kYDY2BYEsoQkucFRuOzOqWqTpMjFwE+zt55bfMlr3EqOPKp+bUHxcfhx4odHHo/3/NH+/2kN7CIS+Bx0lj9KqAaY90ERi1aVK2MNdaXBU035bs5vg1+g/iAfLdhkzyr7OO1PwhFd9vM4TuyxGWetuA07g5twPQ+6b7nbO+5rWZdvy7k6L7j" Jan 27 02:57:36 volumio go-librespot[26031]: time="2026-01-27T02:57:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:36 volumio go-librespot[26031]: time="2026-01-27T02:57:36+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:36 volumio go-librespot[26031]: time="2026-01-27T02:57:36+07:00" level=debug msg="completed challenge" Jan 27 02:57:36 volumio go-librespot[26031]: time="2026-01-27T02:57:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:36 volumio volumio-remote-updater[628]: [2026-01-27 02:57:36] [connect] Successful connection Jan 27 02:57:36 volumio volumio[26009]: info: MYVOLUMIO Environment detected Jan 27 02:57:37 volumio volumio[26009]: info: Plugin folders cleanup Jan 27 02:57:37 volumio volumio[26009]: info: Scanning into folder /volumio/app/plugins/ Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category audio_interface Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category miscellanea Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category music_service Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category plugins.json Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category system_controller Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category user_interface Jan 27 02:57:37 volumio volumio[26009]: info: Scanning into folder /data/plugins/ Jan 27 02:57:37 volumio volumio[26009]: info: Scanning category music_service Jan 27 02:57:37 volumio volumio[26009]: info: Plugin folders cleanup completed Jan 27 02:57:37 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:57:37 volumio volumio[26009]: info: ----- Core plugins startup ---- Jan 27 02:57:37 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:57:37 volumio volumio[26009]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 02:57:37 volumio volumio[26009]: info: Adding plugin upnp to MyMusic Plugins Jan 27 02:57:37 volumio volumio[26009]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 02:57:37 volumio volumio[26009]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 02:57:37 volumio volumio[26009]: info: Loading plugins from folder /data/plugins/ Jan 27 02:57:37 volumio volumio[26009]: info: Loading plugin "system"... Jan 27 02:57:37 volumio volumio[26009]: info: Loading plugin "appearance"... Jan 27 02:57:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "network"... Jan 27 02:57:39 volumio volumio[26009]: info: Refreshing Cached IP Addresses Jan 27 02:57:39 volumio sudo[26047]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 02:57:39 volumio sudo[26047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:39 volumio sudo[26049]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 02:57:39 volumio sudo[26047]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "services"... Jan 27 02:57:39 volumio sudo[26049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "alsa_controller"... Jan 27 02:57:39 volumio sudo[26049]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:39 volumio sudo[26057]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 02:57:39 volumio sudo[26057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:39 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "wizard"... Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "networkfs"... Jan 27 02:57:39 volumio volumio[26009]: info: Starting Udev Watcher for removable devices Jan 27 02:57:39 volumio volumio[26009]: info: Ignoring mount for partition: boot Jan 27 02:57:39 volumio volumio[26009]: info: Ignoring mount for partition: volumio Jan 27 02:57:39 volumio volumio[26009]: info: Ignoring mount for partition: volumio_data Jan 27 02:57:39 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "volumio_command_line_client"... Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "upnp"... Jan 27 02:57:39 volumio volumio[26009]: info: [1769457459479] Starting Upmpd Daemon Jan 27 02:57:39 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "my_music"... Jan 27 02:57:39 volumio volumio[26009]: info: Loading plugin "mpd"... Jan 27 02:57:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 27 02:57:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:39 volumio go-librespot[26080]: go-librespot daemon starting... Jan 27 02:57:39 volumio go-librespot[26081]: time="2026-01-27T02:57:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:39 volumio go-librespot[26081]: time="2026-01-27T02:57:39+07:00" level=debug msg="app state loaded" Jan 27 02:57:39 volumio go-librespot[26081]: time="2026-01-27T02:57:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:40 volumio volumio[26009]: info: Loading plugin "upnp_browser"... Jan 27 02:57:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+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 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+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 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=info msg="zeroconf server listening on port 35699" Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=debug msg="obtained new client token: AAAbICss5o3OYGYsLZhW04eAx2PKD3NRtMdahOP69yTLE4WtzAetk//8+6SGYkAo8syipdCJZ71nv9gvDBamgWUPg3/eGQO45+eAeJD8GeZGuNaNPu32J6232RLwViEiwzLBHkCal7nb12WC9TB83W/0fVsxuHOYHl8KpLvzlPsRWKf4zNl5spkQKGYQzyO5qlh+0JmkjxyB2vmE1K6z0FjUYcPtJc352XOUxSFOELubMqTuTrYG02aE2a0=" Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=debug msg="completed challenge" Jan 27 02:57:40 volumio go-librespot[26081]: time="2026-01-27T02:57:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:42 volumio sudo[26057]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:43 volumio volumio[26009]: info: Starting UPNP Browser Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "alarm-clock"... Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "airplay_emulation"... Jan 27 02:57:43 volumio volumio[26009]: info: Starting Shairport Sync Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "last_100"... Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "webradio"... Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "i2s_dacs"... Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "volumiodiscovery"... Jan 27 02:57:43 volumio volumio[26009]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 02:57:43 volumio volumio[26009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:57:43 volumio volumio[26009]: *** WARNING *** For more information see Jan 27 02:57:43 volumio volumio[26009]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 02:57:43 volumio volumio[26009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:57:43 volumio volumio[26009]: *** WARNING *** For more information see Jan 27 02:57:43 volumio node[26009]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 02:57:43 volumio node[26009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:57:43 volumio node[26009]: *** WARNING *** For more information see Jan 27 02:57:43 volumio node[26009]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 02:57:43 volumio node[26009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:57:43 volumio node[26009]: *** WARNING *** For more information see Jan 27 02:57:43 volumio volumio[26009]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 02:57:43 volumio volumio[26009]: info: Discovery: Started advertising with name: Volumio Jan 27 02:57:43 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 02:57:43 volumio volumio[26009]: info: Loading plugin "spop"... Jan 27 02:57:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 27 02:57:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:44 volumio go-librespot[26091]: go-librespot daemon starting... Jan 27 02:57:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+07:00" level=debug msg="app state loaded" Jan 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+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 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+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 27 02:57:44 volumio go-librespot[26092]: time="2026-01-27T02:57:44+07:00" level=info msg="zeroconf server listening on port 45027" Jan 27 02:57:45 volumio go-librespot[26092]: time="2026-01-27T02:57:45+07:00" level=debug msg="obtained new client token: AAD2WO0aWX8OmiFikvv9X2ghFM02Y67vgXU/wJU836ViFoAEVp2DNlEwiCYtDovoDtHP1F07wro6mqClW6qC2y0Tzv/J3K3yraR8rZVZNu62dulG9dHRjfbmzzDyRKv4rufWqjN2rZrL94A54wPpAiITDA97QjvBj70vOL/v0wyWjUIrkGlRyMvIF0C5KhUmTbap/r03uiQ74DUnsPSyuvHzv3lLYQRcNyr5pCwrG4h9rC7t2bO22nY0" Jan 27 02:57:45 volumio go-librespot[26092]: time="2026-01-27T02:57:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:45 volumio go-librespot[26092]: time="2026-01-27T02:57:45+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:45 volumio go-librespot[26092]: time="2026-01-27T02:57:45+07:00" level=debug msg="completed challenge" Jan 27 02:57:45 volumio go-librespot[26092]: time="2026-01-27T02:57:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:45 volumio volumio[26009]: info: Loading plugin "ytcr"... Jan 27 02:57:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:48 volumio volumio[26009]: info: Loading plugin "ytmusic"... Jan 27 02:57:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 27 02:57:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:48 volumio go-librespot[26099]: go-librespot daemon starting... Jan 27 02:57:48 volumio go-librespot[26100]: time="2026-01-27T02:57:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:48 volumio go-librespot[26100]: time="2026-01-27T02:57:48+07:00" level=debug msg="app state loaded" Jan 27 02:57:48 volumio go-librespot[26100]: time="2026-01-27T02:57:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+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 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+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 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=info msg="zeroconf server listening on port 38805" Jan 27 02:57:49 volumio volumio-remote-updater[628]: [2026-01-27 02:57:49] [connect] Successful connection Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "outputs"... Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=debug msg="obtained new client token: AAB2EWVf0hGahix3DLA/jOBb+TLcoEqO4W5Y0qB0pjZghsSbDQIP2q+fP3LYadzmE32rFPQIix1OPcl1lDYAHNHtEm1GqQCdwwcepDyg/y4LCFh6+zmzH4cKHSkJlphBXCD0atSuV3QIxD3vxmPZ2ovSgniPuFtZ+li9zzoXBOWm8UVZaY8gaV4pTWkC+AFDTqGLsfqpoJ5D2wuEWN/lVfcLBAe1NsQdv8gO6HLKNr/Rdwlg/n9G5XJQJvc=" Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "albumart"... Jan 27 02:57:49 volumio volumio[26009]: info: Plugin example_plugin is not enabled Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "inputs"... Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "updater_comm"... Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=debug msg="completed challenge" Jan 27 02:57:49 volumio go-librespot[26100]: time="2026-01-27T02:57:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:49 volumio volumio[26009]: info: Plugin mpdemulation is not enabled Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "rest_api"... Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "websocket"... Jan 27 02:57:49 volumio volumio[26009]: info: Starting Socket.io Server version 1.7.4 Jan 27 02:57:49 volumio volumio[26009]: info: Loading plugin "RoonBridge"... Jan 27 02:57:50 volumio volumio[26009]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 02:57:50 volumio volumio[26009]: info: Loading i18n strings for locale en Jan 27 02:57:50 volumio volumio[26009]: Updating browse sources language Jan 27 02:57:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:50 volumio volumio[26122]: Forking 3 albumart workers Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::initPlayerControls Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:57:50 volumio volumio[26009]: Express server listening on port 3000 Jan 27 02:57:50 volumio volumio[26009]: [Metrics] WebUI: 16s 138.25ms Jan 27 02:57:50 volumio volumio[26009]: info: CoreStateMachine::resetVolumioState Jan 27 02:57:50 volumio volumio[26009]: info: CoreStateMachine::getcurrentVolume Jan 27 02:57:50 volumio volumio[26009]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:57:50 volumio sudo[26169]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 02:57:50 volumio sudo[26169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:50 volumio sudo[26169]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:50 volumio sudo[26171]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 02:57:50 volumio sudo[26171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:51 volumio sudo[26171]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:51 volumio volumio[26009]: info: Volumio Network Manager: Network status updated: 1 Jan 27 02:57:51 volumio volumio[26009]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::pushState Jan 27 02:57:51 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::updateTrackBlock Jan 27 02:57:51 volumio volumio[26009]: info: CorePlayQueue::getTrackBlock Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:57:51 volumio volumio-remote-updater[628]: [2026-01-27 02:57:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769457469 101 Jan 27 02:57:51 volumio volumio[26009]: 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 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:51 volumio volumio[26009]: info: Reloading queue from file Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::setRepeat null single undefined Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::pushState Jan 27 02:57:51 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::setRandom null Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::pushState Jan 27 02:57:51 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:51 volumio volumio[26009]: info: Setting Device type: Raspberry PI Jan 27 02:57:51 volumio volumio[26009]: info: Completed loading Core Plugins Jan 27 02:57:51 volumio volumio[26009]: info: Preparing to generate the ALSA configuration file Jan 27 02:57:51 volumio volumio[26009]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:57:51 volumio volumio[26009]: info: CoreStateMachine::pushState Jan 27 02:57:51 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:51 volumio volumio[26009]: info: Asound.conf file unchanged, so no further update is needed Jan 27 02:57:51 volumio volumio[26009]: info: Output device has changed, restarting MPD Jan 27 02:57:51 volumio volumio[26009]: info: Output device has changed, restarting Shairport Sync Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:51 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:52 volumio sudo[26185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 02:57:52 volumio sudo[26185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:52 volumio sudo[26187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 02:57:52 volumio sudo[26187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:52 volumio sudo[26189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 02:57:52 volumio sudo[26189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:52 volumio sudo[26187]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:52 volumio volumio[26009]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:57:52 volumio volumio[26009]: info: ___________ START PLUGINS ___________ Jan 27 02:57:52 volumio volumio[26009]: info: ControllerMpd::onStart: Initializing MPD Jan 27 02:57:52 volumio volumio[26009]: info: Creating MPD Configuration file Jan 27 02:57:52 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 02:57:52 volumio sudo[26185]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:52 volumio volumio[26009]: info: [1769457472239] CoreMusicLibrary::Adding element Media Servers Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:52 volumio sudo[26198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 02:57:52 volumio sudo[26198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:52 volumio sudo[26198]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:52 volumio sudo[26200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 02:57:52 volumio sudo[26200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:52 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 02:57:52 volumio volumio[26009]: info: UPNP Browser: Client initialized successfully Jan 27 02:57:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 02:57:52 volumio systemd[1]: mpd.service: Consumed 7.350s CPU time. Jan 27 02:57:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 02:57:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 02:57:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 02:57:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 02:57:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 02:57:52 volumio volumio[26009]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:52 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 02:57:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 02:57:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 02:57:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 02:57:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 02:57:52 volumio volumio[26009]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:52 volumio volumio[26009]: info: [1769457472640] CoreMusicLibrary::Adding element Last_100 Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:52 volumio volumio[26009]: info: [1769457472649] CoreMusicLibrary::Adding element Webradio Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:57:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 02:57:52 volumio volumio[26009]: info: Initializing BBC Radios Jan 27 02:57:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 27 02:57:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:52 volumio go-librespot[26215]: go-librespot daemon starting... Jan 27 02:57:52 volumio go-librespot[26218]: time="2026-01-27T02:57:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:52 volumio go-librespot[26218]: time="2026-01-27T02:57:52+07:00" level=debug msg="app state loaded" Jan 27 02:57:52 volumio go-librespot[26218]: time="2026-01-27T02:57:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:57:52 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:53 volumio volumio[26009]: info: Creating Spotify config file Jan 27 02:57:53 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:53 volumio sudo[26214]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 02:57:53 volumio sudo[26214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 02:57:53 volumio sudo[26214]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:53 volumio go-librespot[26218]: time="2026-01-27T02:57:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 02:57:53 volumio go-librespot[26218]: time="2026-01-27T02:57:53+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 27 02:57:53 volumio go-librespot[26218]: time="2026-01-27T02:57:53+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 27 02:57:53 volumio go-librespot[26218]: time="2026-01-27T02:57:53+07:00" level=info msg="zeroconf server listening on port 46567" Jan 27 02:57:53 volumio volumio[26134]: Starting albumart workers Jan 27 02:57:53 volumio go-librespot[26218]: time="2026-01-27T02:57:53+07:00" level=debug msg="obtained new client token: AADLmYNhHL0IZ9ickKfu61gzVfaHhN0ljLa+i1KpL2xbJb6irlsW8H0HFrP1w7PMENJeiGvRQ/yw0cXtD9aQVVrWdjkwiCcdnEqBcoN+1qa7tsz8pczzSTNm6DramPOzvlK7O1aWuEJkc9c38WOeDDmkLW6je1F5GoV3AGAYcB1CrBGXHQLdkkia9DRImFw3GlNId65SsPa8jLR9ebPJsBnBatTyDM3JeSbMRO9IcO+B+8N/7Df3z1q2GhQ=" Jan 27 02:57:53 volumio volumio[26135]: Starting albumart workers Jan 27 02:57:53 volumio go-librespot[26218]: time="2026-01-27T02:57:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:57:54 volumio go-librespot[26218]: time="2026-01-27T02:57:54+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:54 volumio go-librespot[26218]: time="2026-01-27T02:57:54+07:00" level=debug msg="completed challenge" Jan 27 02:57:54 volumio volumio[26136]: Starting albumart workers Jan 27 02:57:54 volumio go-librespot[26218]: time="2026-01-27T02:57:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:54 volumio volumio[26009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:54 volumio volumio[26009]: info: [1769457474274] CoreMusicLibrary::Adding element YouTube Music Jan 27 02:57:54 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:54 volumio volumio[26009]: Cannot find translation for source YouTube Music Jan 27 02:57:54 volumio volumio[26009]: info: Volumio Calling Home Jan 27 02:57:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:54 volumio sudo[26239]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 02:57:54 volumio sudo[26239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:54 volumio sudo[26239]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:54 volumio volumio[26009]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 02:57:54 volumio volumio[26009]: info: Discovery: Found device Volumio Jan 27 02:57:54 volumio volumio[26009]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:55 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:55 volumio volumio[26009]: info: MPD Permissions set Jan 27 02:57:55 volumio volumio[26009]: info: MPD Permissions set Jan 27 02:57:55 volumio volumio[26009]: info: Upmpdcli Daemon Started Jan 27 02:57:55 volumio volumio[26009]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 02:57:55 volumio volumio[26009]: info: Discovery: Found device Volumio Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:55 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:55 volumio volumio[26009]: info: Spotify config file written Jan 27 02:57:55 volumio sudo[26245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 02:57:55 volumio sudo[26245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:57:55 volumio go-librespot[26247]: go-librespot daemon starting... Jan 27 02:57:55 volumio sudo[26245]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:55 volumio go-librespot[26248]: time="2026-01-27T02:57:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:57:55 volumio go-librespot[26248]: time="2026-01-27T02:57:55+07:00" level=debug msg="app state loaded" Jan 27 02:57:55 volumio go-librespot[26248]: time="2026-01-27T02:57:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:57:55 volumio volumio[26009]: 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 27 02:57:55 volumio volumio[26009]: info: Volumio called home Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:55 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:56 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:57:56 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:57:56 volumio volumio[26009]: info: No need to fix Spotify hosts Jan 27 02:57:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+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 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+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 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+07:00" level=info msg="zeroconf server listening on port 40621" Jan 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+07:00" level=debug msg="obtained new client token: AACXS98Volo941igD5MBvTchG/5DbnjBL3GRLb1T3qUuf8I6sqbAhMoaR8n4zM4tGu7X62BI+sp54S7326NXMID1ho8J1hnDV3Gwp22Ec50Xk9gGB9SUwQcUPGd0/HYf2ceZwS6F9kVwOJKe+wkIv6hecsttSrbeIX0d7Wtuf23goDZUxDG/EVoZRSLilNDXmc5S0ME35lM+V0HPtDhIuRQnc16lAMkHIxXgobXZ66NFpaUVfJ1His1fSPM=" Jan 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+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 27 02:57:56 volumio go-librespot[26248]: time="2026-01-27T02:57:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 02:57:56 volumio volumio[26009]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 02:57:56 volumio volumio[26009]: SPOTIFY: BQCLB0Bsv1HDQb3IEN1QFRhfHJptI67Jy1hEoQAJJZXSoc_P9QXpEFL4EcJ9RQaaHn36QayzJIPqACqFOlyi8oRDxOp_eFC3RTJqBzuoTLL1WCxO0XLNS0bBMcas5_ZVyFWeHC4LMO9FCJFELcXJ7YcuGT73DszDJVq68tV82NozTZXo-Ytg0OpidvAz7XuR4-PuUILsuwgVKQfCj_wdBQtjae7s2Xz8MJoEKo9WC5vxgUEisGFyiFggbZhM88uH08HMkiul48j587etVK2Ugg2n604hWk_zz3apSZVjsSdEPwpNs73KbsqW Jan 27 02:57:56 volumio volumio[26009]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 02:57:56 volumio volumio[26009]: info: New Spotify access token = BQCLB0Bsv1HDQb3IEN1QFRhfHJptI67Jy1hEoQAJJZXSoc_P9QXpEFL4EcJ9RQaaHn36QayzJIPqACqFOlyi8oRDxOp_eFC3RTJqBzuoTLL1WCxO0XLNS0bBMcas5_ZVyFWeHC4LMO9FCJFELcXJ7YcuGT73DszDJVq68tV82NozTZXo-Ytg0OpidvAz7XuR4-PuUILsuwgVKQfCj_wdBQtjae7s2Xz8MJoEKo9WC5vxgUEisGFyiFggbZhM88uH08HMkiul48j587etVK2Ugg2n604hWk_zz3apSZVjsSdEPwpNs73KbsqW Jan 27 02:57:56 volumio volumio[26009]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 02:57:56 volumio volumio[26009]: info: Starting Shairport Sync Jan 27 02:57:56 volumio volumio[26009]: info: Starting Shairport Sync Jan 27 02:57:57 volumio go-librespot[26248]: time="2026-01-27T02:57:57+07:00" level=debug msg="completed keyexchange" Jan 27 02:57:57 volumio go-librespot[26248]: time="2026-01-27T02:57:57+07:00" level=debug msg="completed challenge" Jan 27 02:57:57 volumio volumio[26009]: info: Starting Shairport Sync Jan 27 02:57:57 volumio sudo[26286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:57:57 volumio sudo[26286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:57 volumio go-librespot[26248]: time="2026-01-27T02:57:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:57:57 volumio sudo[26290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:57:57 volumio sudo[26290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:57:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:57:57 volumio sudo[26288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:57:57 volumio sudo[26288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:57:57 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 02:57:57 volumio volumio[26009]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:57 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:57 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 02:57:57 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 02:57:57 volumio systemd[1]: shairport-sync.service: Consumed 2.472s CPU time. Jan 27 02:57:57 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 02:57:57 volumio sudo[26290]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:57 volumio sudo[26286]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:57 volumio sudo[26288]: pam_unix(sudo:session): session closed for user root Jan 27 02:57:57 volumio volumio[26009]: info: Shairport-Sync Started Jan 27 02:57:57 volumio volumio[26009]: Error adding Membership: Error: addMembership EINVAL Jan 27 02:57:57 volumio volumio[26009]: info: Shairport-Sync Started Jan 27 02:57:57 volumio volumio[26009]: info: Shairport-Sync Started Jan 27 02:57:57 volumio volumio[26009]: 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 27 02:57:57 volumio volumio[26009]: info: Spotify Successfully logged in Jan 27 02:57:57 volumio volumio[26009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:57:57 volumio volumio[26009]: info: [1769457477577] CoreMusicLibrary::Adding element Spotify Jan 27 02:57:57 volumio volumio[26009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:57:57 volumio volumio[26009]: Cannot find translation for source YouTube Music Jan 27 02:57:57 volumio volumio[26009]: Cannot find translation for source Spotify Jan 27 02:57:58 volumio volumio[26009]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 02:57:58 volumio volumio[26009]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:57:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:57:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:57:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:57:58 volumio volumio[26009]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:57:58 volumio volumio[26009]: info: CoreCommandRouter::volumioGetState Jan 27 02:57:58 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:58 volumio volumio[26009]: info: CoreStateMachine::pushState Jan 27 02:57:58 volumio volumio[26009]: info: CorePlayQueue::getTrack 0 Jan 27 02:57:58 volumio volumio[26009]: info: CoreCommandRouter::volumioPushState Jan 27 02:57:59 volumio volumio[26009]: info: go-librespot daemon successfully initialized Jan 27 02:58:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 27 02:58:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:00 volumio go-librespot[26325]: go-librespot daemon starting... Jan 27 02:58:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:00 volumio mpd[26237]: 2026-01-27T02:58:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 02:58:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 02:58:00 volumio sudo[26189]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:00 volumio sudo[26200]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+07:00" level=debug msg="app state loaded" Jan 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:00 volumio volumio[26009]: error: MPD error: The expression evaluated to a falsy value: Jan 27 02:58:00 volumio volumio[26009]: assert.ok(self.idling) Jan 27 02:58:00 volumio volumio[26009]: error: The expression evaluated to a falsy value: Jan 27 02:58:00 volumio volumio[26009]: assert.ok(self.idling) Jan 27 02:58:00 volumio volumio[26009]: info: MPD running with PID26237 Jan 27 02:58:00 volumio volumio[26009]: ,establishing connection Jan 27 02:58:00 volumio volumio[26009]: error: updateQueue error: null Jan 27 02:58:00 volumio volumio[26009]: info: Completed starting Core Plugins Jan 27 02:58:00 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:58:00 volumio volumio[26009]: info: ----- MyVolumio plugins startup ---- Jan 27 02:58:00 volumio volumio[26009]: info: ------------------------------------------- Jan 27 02:58:00 volumio volumio[26009]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 02:58:00 volumio volumio[26009]: error: updateQueue error: null Jan 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+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 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+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 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+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 27 02:58:00 volumio go-librespot[26326]: time="2026-01-27T02:58:00+07:00" level=info msg="zeroconf server listening on port 44319" Jan 27 02:58:01 volumio go-librespot[26326]: time="2026-01-27T02:58:01+07:00" level=debug msg="obtained new client token: AABWUBFrh+gCo26deDgu3i/2Dy8OHvx6T8V2K8LbQlHiB88pPVT8jkl5DPJQ0RmBTL9KErsq46x7JJSNJLEbx4uwwtxYneX4V+IjdnUCTzjAESlIX+vmJnjr9okKAcTi5R36CKH9hVI7451eNB/mQZxy5kx3mYtJbV3Utu7OpgrR9Wa/j6chkPuC7Jzkfey/AHkVSjmainoca3vfQ2khaNKgSkXc5XwXE2WIOWPww3u3mMwlNPz0dcAn" Jan 27 02:58:01 volumio go-librespot[26326]: time="2026-01-27T02:58:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:01 volumio go-librespot[26326]: time="2026-01-27T02:58:01+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:01 volumio go-librespot[26326]: time="2026-01-27T02:58:01+07:00" level=debug msg="completed challenge" Jan 27 02:58:01 volumio go-librespot[26326]: time="2026-01-27T02:58:01+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 27 02:58:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:02 volumio volumio[26009]: info: Initializing connection to go-librespot Websocket Jan 27 02:58:02 volumio volumio[26009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 27 02:58:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:04 volumio go-librespot[26339]: go-librespot daemon starting... Jan 27 02:58:04 volumio go-librespot[26340]: time="2026-01-27T02:58:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:04 volumio go-librespot[26340]: time="2026-01-27T02:58:04+07:00" level=debug msg="app state loaded" Jan 27 02:58:04 volumio go-librespot[26340]: time="2026-01-27T02:58:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+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 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+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 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=info msg="zeroconf server listening on port 40667" Jan 27 02:58:05 volumio volumio[26009]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=debug msg="obtained new client token: AAA7e2muOEPyx1XodEse7ERQqC5XiApZdbeqynCeps9oZmWRWftK5V3wbN7HmEP5dITgXn/LC4u8+REw/Wfvu43WOfBV28WODNZVr+rwxc/qzKcIXip1ctNQGRSrJAXSEkFYnhWiMEShHQaITp4w8BB3zPIMA6jBEeiNfcNrlMdevjWr/zVFN6SGlI6pWCGNKkYriT1O8PmvQvfq5a9hs7FpX7hZRKZpGPUpZcrbaJAftPRe0WsRICdXzDg=" Jan 27 02:58:05 volumio volumio[26009]: info: Initializing connection to go-librespot Websocket Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=debug msg="new websocket client" Jan 27 02:58:05 volumio volumio[26009]: info: Connection to go-librespot Websocket established Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+07:00" level=debug msg="completed challenge" Jan 27 02:58:05 volumio go-librespot[26340]: time="2026-01-27T02:58:05+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 27 02:58:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:05 volumio volumio[26009]: info: Connection to go-librespot Websocket closed Jan 27 02:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:08 volumio volumio[26009]: info: Getting Spotify volume Jan 27 02:58:08 volumio volumio[26009]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 02:58:08 volumio volumio[26009]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:58:08 volumio volumio[26009]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 02:58:08 volumio volumio[26009]: errno: -111, Jan 27 02:58:08 volumio volumio[26009]: code: 'ECONNREFUSED', Jan 27 02:58:08 volumio volumio[26009]: syscall: 'connect', Jan 27 02:58:08 volumio volumio[26009]: address: '127.0.0.1', Jan 27 02:58:08 volumio volumio[26009]: port: 9879, Jan 27 02:58:08 volumio volumio[26009]: response: undefined Jan 27 02:58:08 volumio volumio[26009]: } Jan 27 02:58:08 volumio volumio[26009]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 02:58:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 27 02:58:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:09 volumio go-librespot[26358]: go-librespot daemon starting... Jan 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+07:00" level=debug msg="app state loaded" Jan 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+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 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+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 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+07:00" level=info msg="zeroconf server listening on port 37539" Jan 27 02:58:09 volumio go-librespot[26359]: time="2026-01-27T02:58:09+07:00" level=debug msg="obtained new client token: AAAONQiYkK6NnQZLhcLerqX6IJYxOHYGVTR2viyA2f9Vq9LalMLqVWCrzeMwJCRNq1NV0nZRqYvZYqJ/5/oHC6p7DwcFtFjhsThxCx8JJcATG7VU6oP0sQz+NjX/KRqiSgt77+l5QOmv7FqzwDdf7miYJTa8meF/3zGqNP2DmKlmAFYVdofk5wSQceSikyfExdObCgSiOHmzNKFPrql5AlDkYKQTDCtmNTp91WF/X8ZaEr8Sz/YKQTt+k/Q=" Jan 27 02:58:10 volumio go-librespot[26359]: time="2026-01-27T02:58:10+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 27 02:58:10 volumio go-librespot[26359]: time="2026-01-27T02:58:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 02:58:10 volumio go-librespot[26359]: time="2026-01-27T02:58:10+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:10 volumio go-librespot[26359]: time="2026-01-27T02:58:10+07:00" level=debug msg="completed challenge" Jan 27 02:58:10 volumio sudo[26383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 02:57' Jan 27 02:58:10 volumio sudo[26383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:10 volumio go-librespot[26359]: time="2026-01-27T02:58: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 27 02:58:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:10 volumio sudo[26383]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:10 volumio volumio-remote-updater[628]: [2026-01-27 02:58:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 02:58:10 volumio volumio-remote-updater[628]: [2026-01-27 02:58:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 02:58:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 02:58:10 volumio systemd[1]: volumio.service: Consumed 1min 2.452s CPU time. Jan 27 02:58:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 02:58:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 02:58:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7906. Jan 27 02:58:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 02:58:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 02:58:10 volumio systemd[1]: volumio.service: Consumed 1min 2.452s CPU time. Jan 27 02:58:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 02:58:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 02:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 27 02:58:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:13 volumio go-librespot[26411]: go-librespot daemon starting... Jan 27 02:58:13 volumio go-librespot[26412]: time="2026-01-27T02:58:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:13 volumio go-librespot[26412]: time="2026-01-27T02:58:13+07:00" level=debug msg="app state loaded" Jan 27 02:58:13 volumio go-librespot[26412]: time="2026-01-27T02:58:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58: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-gew4.spotify.com:80]" Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+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 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+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 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+07:00" level=info msg="zeroconf server listening on port 42565" Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+07:00" level=debug msg="obtained new client token: AACctvBaRORXC6d3zlOpTcnIoC8enm/LByLVXrq/LVbxxlf+XFgIpqTPtUqCP8Ifk+bvI+O8lsikJ7ru7dJ0nqYaoRVMB5X97l7rfHH0qWHwSCEhop20u5xW8yGI5hzf4rh+wjFm49/D8KX0rF6nB5ENzIBA/B1JGEu87IDs9acvHf9ZEMEVZOBoyhj0WIbxWGhWgBNpQf25O4qIokr283zXUX9ebmkyrIVrQ8G2CbDDjqNdHJ/kFCDc2qQ=" Jan 27 02:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+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 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 02:58:14 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:14 volumio volumio[26396]: info: ----- Volumio3 ---- Jan 27 02:58:14 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:14 volumio volumio[26396]: info: ----- System startup ---- Jan 27 02:58:14 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+07:00" level=debug msg="completed challenge" Jan 27 02:58:14 volumio go-librespot[26412]: time="2026-01-27T02:58:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:15 volumio volumio-remote-updater[628]: [2026-01-27 02:58:15] [connect] Successful connection Jan 27 02:58:16 volumio volumio[26396]: info: MYVOLUMIO Environment detected Jan 27 02:58:16 volumio volumio[26396]: info: Plugin folders cleanup Jan 27 02:58:16 volumio volumio[26396]: info: Scanning into folder /volumio/app/plugins/ Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category audio_interface Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category miscellanea Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category music_service Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category plugins.json Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category system_controller Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category user_interface Jan 27 02:58:16 volumio volumio[26396]: info: Scanning into folder /data/plugins/ Jan 27 02:58:16 volumio volumio[26396]: info: Scanning category music_service Jan 27 02:58:16 volumio volumio[26396]: info: Plugin folders cleanup completed Jan 27 02:58:16 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:16 volumio volumio[26396]: info: ----- Core plugins startup ---- Jan 27 02:58:16 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:16 volumio volumio[26396]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 02:58:16 volumio volumio[26396]: info: Adding plugin upnp to MyMusic Plugins Jan 27 02:58:16 volumio volumio[26396]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 02:58:16 volumio volumio[26396]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 02:58:16 volumio volumio[26396]: info: Loading plugins from folder /data/plugins/ Jan 27 02:58:16 volumio volumio[26396]: info: Loading plugin "system"... Jan 27 02:58:16 volumio volumio[26396]: info: Loading plugin "appearance"... Jan 27 02:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 27 02:58:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:18 volumio go-librespot[26431]: go-librespot daemon starting... Jan 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+07:00" level=debug msg="app state loaded" Jan 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "network"... Jan 27 02:58:18 volumio volumio[26396]: info: Refreshing Cached IP Addresses Jan 27 02:58:18 volumio sudo[26439]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 02:58:18 volumio sudo[26439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:18 volumio sudo[26441]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 02:58:18 volumio sudo[26441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "services"... Jan 27 02:58:18 volumio sudo[26439]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "alsa_controller"... Jan 27 02:58:18 volumio sudo[26441]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:18 volumio sudo[26449]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 02:58:18 volumio sudo[26449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:18 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "wizard"... Jan 27 02:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "networkfs"... Jan 27 02:58:18 volumio volumio[26396]: info: Starting Udev Watcher for removable devices Jan 27 02:58:18 volumio volumio[26396]: info: Ignoring mount for partition: boot Jan 27 02:58:18 volumio volumio[26396]: info: Ignoring mount for partition: volumio Jan 27 02:58:18 volumio volumio[26396]: info: Ignoring mount for partition: volumio_data Jan 27 02:58:18 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "volumio_command_line_client"... Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "upnp"... Jan 27 02:58:18 volumio volumio[26396]: info: [1769457498578] Starting Upmpd Daemon Jan 27 02:58:18 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "my_music"... Jan 27 02:58:18 volumio volumio[26396]: info: Loading plugin "mpd"... Jan 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58: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-gew4.spotify.com:80]" Jan 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+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 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+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 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+07:00" level=info msg="zeroconf server listening on port 33611" Jan 27 02:58:18 volumio go-librespot[26432]: time="2026-01-27T02:58:18+07:00" level=debug msg="obtained new client token: AABlIkeThPaOOX9lj5iNf1qiMeKLsLXBm2G0K5d2UsGZYVVhOECcdeOeS/yLvAqhQrVHGfKSea2jqj0w8X/B0dkl9/O1Ft7JDZg+88Cy2sBrKlPnT/nibhBVg9THx0uxpjyqij43tsRkxerPJje6y3pLywE1zUOFpFTFsfndyEw1MntaS3roW6EFQoWJ+WgngyWBw9rDbSfrp8tPUCBzFgg7jFiZsqEm0LjLyvPj2pJoykX/KURO70OflG0=" Jan 27 02:58:19 volumio go-librespot[26432]: time="2026-01-27T02:58:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:19 volumio go-librespot[26432]: time="2026-01-27T02:58:19+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:19 volumio go-librespot[26432]: time="2026-01-27T02:58:19+07:00" level=debug msg="completed challenge" Jan 27 02:58:19 volumio go-librespot[26432]: time="2026-01-27T02:58: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 27 02:58:19 volumio volumio[26396]: info: Loading plugin "upnp_browser"... Jan 27 02:58:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:21 volumio sudo[26449]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:22 volumio volumio[26396]: info: Starting UPNP Browser Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "alarm-clock"... Jan 27 02:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "airplay_emulation"... Jan 27 02:58:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 27 02:58:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:22 volumio volumio[26396]: info: Starting Shairport Sync Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "last_100"... Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "webradio"... Jan 27 02:58:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:22 volumio go-librespot[26476]: go-librespot daemon starting... Jan 27 02:58:22 volumio go-librespot[26477]: time="2026-01-27T02:58:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:22 volumio go-librespot[26477]: time="2026-01-27T02:58:22+07:00" level=debug msg="app state loaded" Jan 27 02:58:22 volumio go-librespot[26477]: time="2026-01-27T02:58:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "i2s_dacs"... Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "volumiodiscovery"... Jan 27 02:58:22 volumio volumio[26396]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 02:58:22 volumio volumio[26396]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:58:22 volumio volumio[26396]: *** WARNING *** For more information see Jan 27 02:58:22 volumio volumio[26396]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 02:58:22 volumio volumio[26396]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:58:22 volumio volumio[26396]: *** WARNING *** For more information see Jan 27 02:58:22 volumio node[26396]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 02:58:22 volumio node[26396]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:58:22 volumio node[26396]: *** WARNING *** For more information see Jan 27 02:58:22 volumio node[26396]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 02:58:22 volumio node[26396]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 02:58:22 volumio volumio[26396]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 02:58:22 volumio node[26396]: *** WARNING *** For more information see Jan 27 02:58:22 volumio volumio[26396]: info: Discovery: Started advertising with name: Volumio Jan 27 02:58:22 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 02:58:22 volumio volumio[26396]: info: Loading plugin "spop"... Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=info msg="zeroconf server listening on port 35493" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="obtained new client token: AABgGJhGCtr/YBvYg5L9QWTqePLqc7cGeh4Di2o408++9+RZvErDoHV+GK/hIla8DvLMJ8WV7Wvu5mMAsfrbzAz1Rbwb6tOJvK2aaSgzGPb83pgu6V7UH8plUtM8E9InIVIO9RuHKWyHhtUpiBDHUR3HME3CtCkt/WLPUgDQp+2Z7iaf6rQ2ZrfMjXyvg2pdMnh06SCD2A/lWllRwbuTwn9n9ub499/xTTvpKU4w9ZlJEMnQUFJIKAZIdDA=" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=debug msg="completed challenge" Jan 27 02:58:23 volumio go-librespot[26477]: time="2026-01-27T02:58:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:24 volumio volumio[26396]: info: Loading plugin "ytcr"... Jan 27 02:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 27 02:58:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:27 volumio go-librespot[26487]: go-librespot daemon starting... Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=debug msg="app state loaded" Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:27 volumio volumio[26396]: info: Loading plugin "ytmusic"... Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=info msg="zeroconf server listening on port 39319" Jan 27 02:58:27 volumio go-librespot[26488]: time="2026-01-27T02:58:27+07:00" level=debug msg="obtained new client token: AADAcn2ziyfm1o6PvSFlsJMqIH0NAVlJmZGsepnC4S6EHbBUycrdJ++zx2DvSBGAEAmxWUs1XMp/zGdIiX4TKvYREOAuLI5tx2urFt4CHhH8MYlRdFW5a75y5Tf6W66mVN974spDi/FBOlD5lS2kasY/67hbzh93ttBX33aE61LtEWSM0rNgYvv5BCMWrdygc3gVxISh5IJ3GYK8bteTTQg2UI/vUqsuf8Xrzbq56SDg/Jk3O/UzwK9PycU=" Jan 27 02:58:28 volumio go-librespot[26488]: time="2026-01-27T02:58:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:28 volumio go-librespot[26488]: time="2026-01-27T02:58:28+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:28 volumio go-librespot[26488]: time="2026-01-27T02:58:28+07:00" level=debug msg="completed challenge" Jan 27 02:58:28 volumio go-librespot[26488]: time="2026-01-27T02:58:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:28 volumio volumio-remote-updater[628]: [2026-01-27 02:58:28] [connect] Successful connection Jan 27 02:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "outputs"... Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "albumart"... Jan 27 02:58:28 volumio volumio[26396]: info: Plugin example_plugin is not enabled Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "inputs"... Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "updater_comm"... Jan 27 02:58:28 volumio volumio[26396]: info: Plugin mpdemulation is not enabled Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "rest_api"... Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "websocket"... Jan 27 02:58:28 volumio volumio[26396]: info: Starting Socket.io Server version 1.7.4 Jan 27 02:58:28 volumio volumio[26396]: info: Loading plugin "RoonBridge"... Jan 27 02:58:29 volumio volumio[26396]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 02:58:29 volumio volumio[26396]: info: Loading i18n strings for locale en Jan 27 02:58:29 volumio volumio[26396]: Updating browse sources language Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:58:29 volumio volumio[26509]: Forking 3 albumart workers Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::initPlayerControls Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:58:29 volumio volumio[26396]: Express server listening on port 3000 Jan 27 02:58:29 volumio volumio[26396]: [Metrics] WebUI: 15s 981.88ms Jan 27 02:58:29 volumio volumio[26396]: info: CoreStateMachine::resetVolumioState Jan 27 02:58:29 volumio volumio[26396]: info: CoreStateMachine::getcurrentVolume Jan 27 02:58:29 volumio volumio[26396]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:58:29 volumio sudo[26551]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 02:58:29 volumio sudo[26551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:29 volumio sudo[26551]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:29 volumio sudo[26553]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 02:58:29 volumio sudo[26553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:29 volumio sudo[26553]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:30 volumio volumio[26396]: info: Volumio Network Manager: Network status updated: 1 Jan 27 02:58:30 volumio volumio[26396]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::pushState Jan 27 02:58:30 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::volumioPushState Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::updateTrackBlock Jan 27 02:58:30 volumio volumio[26396]: info: CorePlayQueue::getTrackBlock Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:58:30 volumio volumio-remote-updater[628]: [2026-01-27 02:58:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769457508 101 Jan 27 02:58:30 volumio volumio[26396]: 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 27 02:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:30 volumio volumio[26396]: info: Reloading queue from file Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::setRepeat null single undefined Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::pushState Jan 27 02:58:30 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::volumioPushState Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::setRandom null Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::pushState Jan 27 02:58:30 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::volumioPushState Jan 27 02:58:30 volumio volumio[26396]: info: Setting Device type: Raspberry PI Jan 27 02:58:30 volumio volumio[26396]: info: Completed loading Core Plugins Jan 27 02:58:30 volumio volumio[26396]: info: Preparing to generate the ALSA configuration file Jan 27 02:58:30 volumio volumio[26396]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:58:30 volumio volumio[26396]: info: CoreStateMachine::pushState Jan 27 02:58:30 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::volumioPushState Jan 27 02:58:30 volumio volumio[26396]: info: Asound.conf file unchanged, so no further update is needed Jan 27 02:58:30 volumio volumio[26396]: info: Output device has changed, restarting MPD Jan 27 02:58:30 volumio volumio[26396]: info: Output device has changed, restarting Shairport Sync Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:30 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:30 volumio sudo[26570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 02:58:30 volumio sudo[26570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:30 volumio sudo[26572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 02:58:30 volumio sudo[26574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 02:58:30 volumio sudo[26572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:30 volumio volumio[26396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:58:30 volumio sudo[26574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:30 volumio volumio[26396]: info: ___________ START PLUGINS ___________ Jan 27 02:58:30 volumio volumio[26396]: info: ControllerMpd::onStart: Initializing MPD Jan 27 02:58:30 volumio volumio[26396]: info: Creating MPD Configuration file Jan 27 02:58:30 volumio sudo[26572]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:58:31 volumio sudo[26570]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:31 volumio volumio[26396]: info: [1769457511018] CoreMusicLibrary::Adding element Media Servers Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:58:31 volumio volumio[26396]: info: UPNP Browser: Client initialized successfully Jan 27 02:58:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:31 volumio sudo[26583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 02:58:31 volumio sudo[26583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:31 volumio sudo[26583]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:31 volumio sudo[26585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 02:58:31 volumio volumio[26396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:31 volumio sudo[26585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:31 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 02:58:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 02:58:31 volumio systemd[1]: mpd.service: Consumed 7.302s CPU time. Jan 27 02:58:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 02:58:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 02:58:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 02:58:31 volumio volumio[26396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:58:31 volumio volumio[26396]: info: [1769457511268] CoreMusicLibrary::Adding element Last_100 Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:58:31 volumio volumio[26396]: info: [1769457511277] CoreMusicLibrary::Adding element Webradio Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:58:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 02:58:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:58:31 volumio volumio[26396]: info: Initializing BBC Radios Jan 27 02:58:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jan 27 02:58:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:31 volumio go-librespot[26606]: go-librespot daemon starting... Jan 27 02:58:31 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 02:58:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 02:58:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 02:58:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 02:58:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 02:58:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 02:58:31 volumio go-librespot[26609]: time="2026-01-27T02:58:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:31 volumio go-librespot[26609]: time="2026-01-27T02:58:31+07:00" level=debug msg="app state loaded" Jan 27 02:58:31 volumio go-librespot[26609]: time="2026-01-27T02:58:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:31 volumio volumio[26396]: info: Creating Spotify config file Jan 27 02:58:31 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:32 volumio sudo[26619]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 02:58:32 volumio sudo[26619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 02:58:32 volumio sudo[26619]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+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 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+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 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+07:00" level=info msg="zeroconf server listening on port 40333" Jan 27 02:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+07:00" level=debug msg="obtained new client token: AABf3b2NbMPrKHQG+o3YRWySivTgjjJnm+DBj/FmMMsCxI1xfnkoSVtqZTi1brUPedTAQuTItf33UCDmlzZmWF5zYH8i9WE14cRVgx4ExfwDYKApS3kSwBwC+G8GuYhbSwZZszeyIetAzHLHnAyR2RnPbPX/jwqjfkpBRfHIeoGU/xD9QKijFlUC9SuH71lO0BbG2YDP0+5AW5w9VQka1kFyKjJ1GkWAVkuVvZX47RxwR66bOOmdttee/zs=" Jan 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:32 volumio go-librespot[26609]: time="2026-01-27T02:58:32+07:00" level=debug msg="completed challenge" Jan 27 02:58:33 volumio volumio[26396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:58:33 volumio volumio[26396]: info: [1769457513032] CoreMusicLibrary::Adding element YouTube Music Jan 27 02:58:33 volumio go-librespot[26609]: time="2026-01-27T02:58:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:33 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:58:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:33 volumio volumio[26396]: Cannot find translation for source YouTube Music Jan 27 02:58:33 volumio volumio[26396]: info: Volumio Calling Home Jan 27 02:58:33 volumio sudo[26625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 02:58:33 volumio volumio[26520]: Starting albumart workers Jan 27 02:58:33 volumio sudo[26625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:33 volumio volumio[26521]: Starting albumart workers Jan 27 02:58:33 volumio volumio[26519]: Starting albumart workers Jan 27 02:58:33 volumio sudo[26625]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:33 volumio volumio[26396]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 02:58:33 volumio volumio[26396]: info: Discovery: Found device Volumio Jan 27 02:58:33 volumio volumio[26396]: info: CoreCommandRouter::volumioGetState Jan 27 02:58:33 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:33 volumio volumio[26396]: info: MPD Permissions set Jan 27 02:58:33 volumio volumio[26396]: info: MPD Permissions set Jan 27 02:58:33 volumio volumio[26396]: info: Upmpdcli Daemon Started Jan 27 02:58:33 volumio volumio[26396]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 02:58:33 volumio volumio[26396]: info: Discovery: Found device Volumio Jan 27 02:58:33 volumio volumio[26396]: info: CoreCommandRouter::volumioGetState Jan 27 02:58:33 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:33 volumio volumio[26396]: info: Spotify config file written Jan 27 02:58:34 volumio sudo[26631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 02:58:34 volumio sudo[26631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:34 volumio volumio[26396]: 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 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:34 volumio go-librespot[26638]: go-librespot daemon starting... Jan 27 02:58:34 volumio sudo[26631]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:34 volumio go-librespot[26641]: time="2026-01-27T02:58:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:34 volumio go-librespot[26641]: time="2026-01-27T02:58:34+07:00" level=debug msg="app state loaded" Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:34 volumio go-librespot[26641]: time="2026-01-27T02:58:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:34 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 02:58:34 volumio volumio[26396]: info: No need to fix Spotify hosts Jan 27 02:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+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 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+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 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=info msg="zeroconf server listening on port 39349" Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=debug msg="obtained new client token: AAAgA0BWtdCpe0iopaqm319hkA9NVLDktzL26DZFuj2EjOfhF0FQJ2F88tjtUMynIRe91/pM/w8FFwDIHjUUTuOFTd421VDvFK46VJZOi0TFk5jTZBX0idYL/VZa2W2jklZ98XuqWcdFIElUgw+J0EgItoALuNbDsPVgXRTOjKJj62eNJ1BIyPLsxvt+UaP6m+65i3hcYfsY3E6qlGhF01cIkDfpeIPPSPUfiTv1sfW3Ncskm0rjIdSoafA=" Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=debug msg="completed challenge" Jan 27 02:58:35 volumio go-librespot[26641]: time="2026-01-27T02:58:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:35 volumio volumio[26396]: info: Volumio called home Jan 27 02:58:35 volumio volumio[26396]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 02:58:35 volumio volumio[26396]: SPOTIFY: BQBOBOhHrrnKFyNjv1OzQSLXZ8BsLAaoqBkjQ0WiQog6WYnWZ8lPb0RD_MHIGg0Tc83eFXMJ_V4zjYJH5LIy-Hhw0zpBlpJ3EV6P5rQjT6rN20UvcQzTy-HJB1EIV7tOy6E2myk-a9jsvOqaIDh46ikufT4psRUrF7zBSeR4fQcNT2BiV_gALIiiKyWcObPZn3aZUf7bemnsatXIkIeNA-dpIJoReINKx-dpxx5ZAsXUMOkRRRfg1NRn3G93N8NW667j43rL1AaVpC6Md0APL6-LYBigk0_ZrcpC7JwZbuwp-AMg5Nf_bUlm Jan 27 02:58:35 volumio volumio[26396]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 02:58:35 volumio volumio[26396]: info: New Spotify access token = BQBOBOhHrrnKFyNjv1OzQSLXZ8BsLAaoqBkjQ0WiQog6WYnWZ8lPb0RD_MHIGg0Tc83eFXMJ_V4zjYJH5LIy-Hhw0zpBlpJ3EV6P5rQjT6rN20UvcQzTy-HJB1EIV7tOy6E2myk-a9jsvOqaIDh46ikufT4psRUrF7zBSeR4fQcNT2BiV_gALIiiKyWcObPZn3aZUf7bemnsatXIkIeNA-dpIJoReINKx-dpxx5ZAsXUMOkRRRfg1NRn3G93N8NW667j43rL1AaVpC6Md0APL6-LYBigk0_ZrcpC7JwZbuwp-AMg5Nf_bUlm Jan 27 02:58:35 volumio volumio[26396]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 02:58:35 volumio volumio[26396]: info: Starting Shairport Sync Jan 27 02:58:35 volumio volumio[26396]: info: Starting Shairport Sync Jan 27 02:58:36 volumio volumio[26396]: info: Starting Shairport Sync Jan 27 02:58:36 volumio sudo[26672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:58:36 volumio sudo[26672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:36 volumio sudo[26676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:58:36 volumio sudo[26676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:36 volumio sudo[26674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 02:58:36 volumio sudo[26674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 02:58:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 02:58:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 02:58:36 volumio systemd[1]: shairport-sync.service: Consumed 2.346s CPU time. Jan 27 02:58:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 02:58:36 volumio sudo[26674]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:36 volumio sudo[26676]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:36 volumio sudo[26672]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:36 volumio volumio[26396]: info: Shairport-Sync Started Jan 27 02:58:36 volumio volumio[26396]: Error adding Membership: Error: addMembership EINVAL Jan 27 02:58:36 volumio volumio[26396]: info: Shairport-Sync Started Jan 27 02:58:36 volumio volumio[26396]: info: Shairport-Sync Started Jan 27 02:58:36 volumio volumio[26396]: info: CoreCommandRouter::volumioGetState Jan 27 02:58:36 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:36 volumio volumio[26396]: 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 27 02:58:36 volumio volumio[26396]: info: Spotify Successfully logged in Jan 27 02:58:36 volumio volumio[26396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 02:58:36 volumio volumio[26396]: info: [1769457516831] CoreMusicLibrary::Adding element Spotify Jan 27 02:58:36 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 02:58:36 volumio volumio[26396]: Cannot find translation for source YouTube Music Jan 27 02:58:36 volumio volumio[26396]: Cannot find translation for source Spotify Jan 27 02:58:37 volumio volumio[26396]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 02:58:37 volumio volumio[26396]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 02:58:37 volumio volumio[26396]: info: VolumeController:: Volume=100 Mute =false Jan 27 02:58:37 volumio volumio[26396]: info: CoreCommandRouter::volumioGetState Jan 27 02:58:37 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:37 volumio volumio[26396]: info: CoreStateMachine::pushState Jan 27 02:58:37 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:37 volumio volumio[26396]: info: CoreCommandRouter::volumioPushState Jan 27 02:58:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Jan 27 02:58:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:38 volumio go-librespot[26711]: go-librespot daemon starting... Jan 27 02:58:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:38 volumio volumio[26396]: info: go-librespot daemon successfully initialized Jan 27 02:58:38 volumio go-librespot[26712]: time="2026-01-27T02:58:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:38 volumio go-librespot[26712]: time="2026-01-27T02:58:38+07:00" level=debug msg="app state loaded" Jan 27 02:58:38 volumio go-librespot[26712]: time="2026-01-27T02:58:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:39 volumio go-librespot[26712]: time="2026-01-27T02:58:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:39 volumio go-librespot[26712]: time="2026-01-27T02:58:39+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 27 02:58:39 volumio go-librespot[26712]: time="2026-01-27T02:58:39+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 27 02:58:39 volumio go-librespot[26712]: time="2026-01-27T02:58:39+07:00" level=info msg="zeroconf server listening on port 43229" Jan 27 02:58:39 volumio mpd[26623]: 2026-01-27T02:58:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 02:58:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 02:58:39 volumio sudo[26574]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:39 volumio sudo[26585]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:39 volumio go-librespot[26712]: time="2026-01-27T02:58:39+07:00" level=debug msg="obtained new client token: AAARH+A8kFgrkK2fTxZOGKrN7EIQjx6JnRAu8rv5n9/FyWpvh3YnDi1TFo2Ps1OX0XTAQzlpRkehqdeYU2QwgX8babmmGPs0NB8/4T8P2CdNPWmYf6N2rSg9ZOu9jjjRvxyjJT1O8v1D3KEnOao95RjIAvY6S8A8uty3oum/MWRyAFzJq+nTPUEqUI5B1YD3tnVZ1EdB/wiDny5mA6zgqvHgfi9ze9bmRG5MpK3MLVkxWqPdo3HeJQy/UNc=" Jan 27 02:58:39 volumio volumio[26396]: error: MPD error: The expression evaluated to a falsy value: Jan 27 02:58:39 volumio volumio[26396]: assert.ok(self.idling) Jan 27 02:58:39 volumio volumio[26396]: error: The expression evaluated to a falsy value: Jan 27 02:58:39 volumio volumio[26396]: assert.ok(self.idling) Jan 27 02:58:39 volumio volumio[26396]: error: updateQueue error: null Jan 27 02:58:39 volumio volumio[26396]: info: MPD running with PID26623 Jan 27 02:58:39 volumio volumio[26396]: ,establishing connection Jan 27 02:58:39 volumio go-librespot[26712]: time="2026-01-27T02:58:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:40 volumio volumio[26396]: info: Completed starting Core Plugins Jan 27 02:58:40 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:40 volumio volumio[26396]: info: ----- MyVolumio plugins startup ---- Jan 27 02:58:40 volumio volumio[26396]: info: ------------------------------------------- Jan 27 02:58:40 volumio volumio[26396]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 02:58:40 volumio volumio[26396]: error: updateQueue error: null Jan 27 02:58:40 volumio go-librespot[26712]: time="2026-01-27T02:58:40+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:40 volumio go-librespot[26712]: time="2026-01-27T02:58:40+07:00" level=debug msg="completed challenge" Jan 27 02:58:40 volumio go-librespot[26712]: time="2026-01-27T02:58:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:41 volumio volumio[26396]: info: Initializing connection to go-librespot Websocket Jan 27 02:58:41 volumio volumio[26396]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:58:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Jan 27 02:58:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:43 volumio go-librespot[26725]: go-librespot daemon starting... Jan 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+07:00" level=debug msg="app state loaded" Jan 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+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 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+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 27 02:58:43 volumio go-librespot[26726]: time="2026-01-27T02:58:43+07:00" level=info msg="zeroconf server listening on port 33541" Jan 27 02:58:44 volumio go-librespot[26726]: time="2026-01-27T02:58:44+07:00" level=debug msg="obtained new client token: AAA/IPVEa9gIa+tuzKoDhYKYZ4dauN3W2SX4Vy598evjX0Tsb4PTkREU7HMF86XvDfwQroRp6I7x7bbVqiykW2aXIb7/vWc7Os0ebj4OjJxiVfp9FfpHatacUWQ+Ch7Zn1bVYGIaQ0Zl5GSeOtpEAha6IDpmEmA+K64uFCQViJzu4tcMCbxT1cjlOuVX17Dz0AapBHG46wWJaH4CBEYbcpzZQStWAsxUyzPOJbs7wlyCAROOw1zpW4pp" Jan 27 02:58:44 volumio go-librespot[26726]: time="2026-01-27T02:58:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:44 volumio go-librespot[26726]: time="2026-01-27T02:58:44+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:44 volumio go-librespot[26726]: time="2026-01-27T02:58:44+07:00" level=debug msg="completed challenge" Jan 27 02:58:44 volumio go-librespot[26726]: time="2026-01-27T02:58:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:44 volumio volumio[26396]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 02:58:44 volumio volumio[26396]: info: Initializing connection to go-librespot Websocket Jan 27 02:58:44 volumio volumio[26396]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 02:58:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Jan 27 02:58:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:47 volumio go-librespot[26733]: go-librespot daemon starting... Jan 27 02:58:47 volumio go-librespot[26734]: time="2026-01-27T02:58:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:47 volumio go-librespot[26734]: time="2026-01-27T02:58:47+07:00" level=debug msg="app state loaded" Jan 27 02:58:47 volumio go-librespot[26734]: time="2026-01-27T02:58:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:47 volumio volumio[26396]: info: Initializing connection to go-librespot Websocket Jan 27 02:58:47 volumio go-librespot[26734]: time="2026-01-27T02:58:47+07:00" level=debug msg="new websocket client" Jan 27 02:58:47 volumio volumio[26396]: info: Connection to go-librespot Websocket established Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=info msg="zeroconf server listening on port 35585" Jan 27 02:58:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="obtained new client token: AADhPQTsGtQi7mqZ1uDjMICQL441U/kfmXt77DFHVugQ4C3GzBrIqCqb41fYjNd5ex7yhTligAFlVEuRg4eciKisxz7BzRbdkuWxDL2hHAHw/F/O55E62aiY6q13irh4b7dJ63inz0H1WuuYauZ3MyV6poTnAV/ny5KlCyo6cb22x6Z4goI1wRrm1/INsTqCaShP+j18i4uwcF1IYwcpjvKzZdfS7fBpI33yJWNpvaZJTpiyzt8EXm69g28=" Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+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 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=debug msg="completed challenge" Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 02:58:48 volumio volumio[26396]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 02:58:48 volumio go-librespot[26734]: time="2026-01-27T02:58:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:48 volumio volumio[26396]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 02:58:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:50 volumio volumio[26396]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 02:58:50 volumio volumio[26396]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 02:58:50 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:50 volumio volumio[26396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 02:58:50 volumio volumio[26396]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 02:58:50 volumio volumio[26396]: info: MyVolumio login type: Token Jan 27 02:58:50 volumio volumio[26396]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 02:58:50 volumio volumio[26396]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 02:58:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Jan 27 02:58:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 02:58:52 volumio go-librespot[26758]: go-librespot daemon starting... Jan 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+07:00" level=debug msg="app state loaded" Jan 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 02:58:52 volumio volumio[26396]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 02:58:52 volumio volumio[26396]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 02:58:52 volumio volumio[26396]: info: Streaming services startup Jan 27 02:58:52 volumio volumio[26396]: info: Starting Streaming Daemon Jan 27 02:58:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:52 volumio sudo[26768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 02:58:52 volumio sudo[26768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 02:58:52 volumio volumio[26396]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 02:58:52 volumio sudo[26768]: pam_unix(sudo:session): session closed for user root Jan 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+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 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+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 27 02:58:52 volumio volumio[26396]: info: Getting Spotify volume Jan 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+07:00" level=info msg="zeroconf server listening on port 33057" Jan 27 02:58:52 volumio volumio[26396]: info: Connection to go-librespot Websocket closed Jan 27 02:58:52 volumio volumio[26396]: error: Cannot start Volumio Streaming Daemon Jan 27 02:58:52 volumio volumio[26396]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 02:58:52 volumio volumio[26396]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 02:58:52 volumio volumio[26396]: 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 27 02:58:52 volumio go-librespot[26759]: time="2026-01-27T02:58:52+07:00" level=debug msg="obtained new client token: AAB1ADZqNPQLPPmh3D8QGTDNG6R1uJjkhfGihHqFFTEfiB42QXL0UimFMaXfuIXDnsM0TDigViTS9kaPSj7dF1s1iG0Me6nDgJxRFMm1tqR89WQSAn9234wwD+dY0T6lMys3itMEwnNDWLgix+WMTVumgibFAMiObt438lCz04BJeFO1smAu+ZR+ECRaH8ozVaU+9L/qsjSc7T8K5szq2IJwiVjNIU+lLoT/BMh1nsPsGRuLH99EnmgWZVU=" Jan 27 02:58:53 volumio go-librespot[26759]: time="2026-01-27T02:58:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 02:58:53 volumio volumio[26396]: info: CoreCommandRouter::volumioGetState Jan 27 02:58:53 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:53 volumio go-librespot[26759]: time="2026-01-27T02:58:53+07:00" level=debug msg="completed keyexchange" Jan 27 02:58:53 volumio go-librespot[26759]: time="2026-01-27T02:58:53+07:00" level=debug msg="completed challenge" Jan 27 02:58:53 volumio volumio[26396]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 02:58:53 volumio volumio[26396]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 02:58:53 volumio volumio[26396]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 02:58:53 volumio volumio[26396]: info: Aligning Spotify Volume to Volumio Volume Jan 27 02:58:53 volumio volumio[26396]: info: CoreCommandRouter::volumioGetState Jan 27 02:58:53 volumio volumio[26396]: info: CorePlayQueue::getTrack 0 Jan 27 02:58:53 volumio volumio[26396]: info: Setting Spotify Volume from Volumio: 100 Jan 27 02:58:53 volumio go-librespot[26759]: time="2026-01-27T02:58:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 02:58:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 02:58:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 02:58:53 volumio volumio[26396]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 02:58:53 volumio volumio[26396]: Error: socket hang up Jan 27 02:58:53 volumio volumio[26396]: at connResetException (node:internal/errors:720:14) Jan 27 02:58:53 volumio volumio[26396]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 02:58:53 volumio volumio[26396]: at Socket.emit (node:events:526:35) Jan 27 02:58:53 volumio volumio[26396]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 02:58:53 volumio volumio[26396]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 02:58:53 volumio volumio[26396]: code: 'ECONNRESET', Jan 27 02:58:53 volumio volumio[26396]: response: undefined Jan 27 02:58:53 volumio volumio[26396]: } Jan 27 02:58:53 volumio volumio[26396]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 02:58:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 02:58:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 02:58:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 02:58:54 volumio sudo[26788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 02:57' Jan 27 02:58:54 volumio sudo[26788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"