Jan 27 10:44:00 volumio volumio-remote-updater[628]: [2026-01-27 10:44:00] [connect] Successful connection Jan 27 10:44:00 volumio volumio[26179]: info: MYVOLUMIO Environment detected Jan 27 10:44:00 volumio volumio[26179]: info: Plugin folders cleanup Jan 27 10:44:00 volumio volumio[26179]: info: Scanning into folder /volumio/app/plugins/ Jan 27 10:44:00 volumio volumio[26179]: info: Scanning category audio_interface Jan 27 10:44:01 volumio volumio[26179]: info: Scanning category miscellanea Jan 27 10:44:01 volumio volumio[26179]: info: Scanning category music_service Jan 27 10:44:01 volumio volumio[26179]: info: Scanning category plugins.json Jan 27 10:44:01 volumio volumio[26179]: info: Scanning category system_controller Jan 27 10:44:01 volumio volumio[26179]: info: Scanning category user_interface Jan 27 10:44:01 volumio volumio[26179]: info: Scanning into folder /data/plugins/ Jan 27 10:44:01 volumio volumio[26179]: info: Scanning category music_service Jan 27 10:44:01 volumio volumio[26179]: info: Plugin folders cleanup completed Jan 27 10:44:01 volumio volumio[26179]: info: ------------------------------------------- Jan 27 10:44:01 volumio volumio[26179]: info: ----- Core plugins startup ---- Jan 27 10:44:01 volumio volumio[26179]: info: ------------------------------------------- Jan 27 10:44:01 volumio volumio[26179]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 10:44:01 volumio volumio[26179]: info: Adding plugin upnp to MyMusic Plugins Jan 27 10:44:01 volumio volumio[26179]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 10:44:01 volumio volumio[26179]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 10:44:01 volumio volumio[26179]: info: Loading plugins from folder /data/plugins/ Jan 27 10:44:01 volumio volumio[26179]: info: Loading plugin "system"... Jan 27 10:44:01 volumio volumio[26179]: info: Loading plugin "appearance"... Jan 27 10:44:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:02 volumio volumio[26179]: info: Loading plugin "network"... Jan 27 10:44:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 10:44:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:03 volumio volumio[26179]: info: Refreshing Cached IP Addresses Jan 27 10:44:03 volumio sudo[26214]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 10:44:03 volumio sudo[26214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:03 volumio sudo[26216]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 10:44:03 volumio sudo[26214]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:03 volumio sudo[26216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:03 volumio go-librespot[26212]: go-librespot daemon starting... Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "services"... Jan 27 10:44:03 volumio sudo[26216]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "alsa_controller"... Jan 27 10:44:03 volumio sudo[26224]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 10:44:03 volumio sudo[26224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=debug msg="app state loaded" Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:03 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "wizard"... Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "networkfs"... Jan 27 10:44:03 volumio volumio[26179]: info: Starting Udev Watcher for removable devices Jan 27 10:44:03 volumio volumio[26179]: info: Ignoring mount for partition: boot Jan 27 10:44:03 volumio volumio[26179]: info: Ignoring mount for partition: volumio Jan 27 10:44:03 volumio volumio[26179]: info: Ignoring mount for partition: volumio_data Jan 27 10:44:03 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "volumio_command_line_client"... Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "upnp"... Jan 27 10:44:03 volumio volumio[26179]: info: [1769485443460] Starting Upmpd Daemon Jan 27 10:44:03 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "my_music"... Jan 27 10:44:03 volumio volumio[26179]: info: Loading plugin "mpd"... Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 10:44:03 volumio go-librespot[26234]: time="2026-01-27T10:44:03+07:00" level=info msg="zeroconf server listening on port 34023" Jan 27 10:44:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:04 volumio go-librespot[26234]: time="2026-01-27T10:44:04+07:00" level=debug msg="obtained new client token: AAAfm2h/QPvBxXnD2UXOGuoI7Ybz7BtJEl9Y8N0ZMk+2UjQ/jelPKzqBk7Ck84zUIHkp0tTp2/ZpZ2dQwTgVrmfae3+Z5Mj+AMzzagYCNvr48gVBTmw6DVnO4ud+kxLUe8eFH8Shqd20YbXKZj5S2Oea6NKxYwdHxIr6DWDPKvgr0shZR/MSI8gzB2vaZE2ZYkTmsJ1+rLfUn/5p1WqE5EK1vvKrFFh5VKiz5iS2n4JyMNNZJ1Bog8Mj7wA=" Jan 27 10:44:04 volumio go-librespot[26234]: time="2026-01-27T10:44:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:04 volumio volumio[26179]: info: Loading plugin "upnp_browser"... Jan 27 10:44:04 volumio go-librespot[26234]: time="2026-01-27T10:44:04+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:04 volumio go-librespot[26234]: time="2026-01-27T10:44:04+07:00" level=debug msg="completed challenge" Jan 27 10:44:04 volumio go-librespot[26234]: time="2026-01-27T10:44:04+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 10:44:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:06 volumio sudo[26224]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:07 volumio volumio[26179]: info: Starting UPNP Browser Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "alarm-clock"... Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "airplay_emulation"... Jan 27 10:44:07 volumio volumio[26179]: info: Starting Shairport Sync Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "last_100"... Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "webradio"... Jan 27 10:44:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 10:44:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:07 volumio go-librespot[26254]: go-librespot daemon starting... Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "i2s_dacs"... Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "volumiodiscovery"... Jan 27 10:44:07 volumio go-librespot[26255]: time="2026-01-27T10:44:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:07 volumio go-librespot[26255]: time="2026-01-27T10:44:07+07:00" level=debug msg="app state loaded" Jan 27 10:44:07 volumio go-librespot[26255]: time="2026-01-27T10:44:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:07 volumio volumio[26179]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:07 volumio volumio[26179]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:07 volumio volumio[26179]: *** WARNING *** For more information see Jan 27 10:44:07 volumio volumio[26179]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:07 volumio volumio[26179]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:07 volumio volumio[26179]: *** WARNING *** For more information see Jan 27 10:44:07 volumio node[26179]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:07 volumio node[26179]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:07 volumio node[26179]: *** WARNING *** For more information see Jan 27 10:44:07 volumio node[26179]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:07 volumio node[26179]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:07 volumio node[26179]: *** WARNING *** For more information see Jan 27 10:44:07 volumio volumio[26179]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 10:44:07 volumio volumio[26179]: info: Discovery: Started advertising with name: Volumio Jan 27 10:44:07 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 10:44:07 volumio volumio[26179]: info: Loading plugin "spop"... Jan 27 10:44:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+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 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+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 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+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 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+07:00" level=info msg="zeroconf server listening on port 41289" Jan 27 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+07:00" level=debug msg="obtained new client token: AAAn3mUPLdYc0qeEggcXzMTa6jZ+rVDPtXLeAGoW/qcYZAC7F9YQnIXD7vFg+EG59qwt2nOjs/wNlQIM8lSbBp6sn0lltyzJ2er/P54N90F6NQ6NF9JS73Hl/XE7+A1oWVyu9tUHA1cHChyPIUSofpSH1AR6aMRRW2Tfp6AAswxMCYpThX9lqS9fYbZqnqc6Uv0IjyroIAm04z+wU267AmWPEHD3hdDRK27ltuSSBtHe1STCIvQDv6fV2tA=" Jan 27 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+07:00" level=debug msg="completed challenge" Jan 27 10:44:08 volumio go-librespot[26255]: time="2026-01-27T10:44:08+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 10:44:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:09 volumio volumio[26179]: info: Loading plugin "ytcr"... Jan 27 10:44:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 10:44:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:12 volumio go-librespot[26265]: go-librespot daemon starting... Jan 27 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+07:00" level=debug msg="app state loaded" Jan 27 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:12 volumio volumio[26179]: info: Loading plugin "ytmusic"... Jan 27 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+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 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+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 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+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 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+07:00" level=info msg="zeroconf server listening on port 34647" Jan 27 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+07:00" level=debug msg="obtained new client token: AAD9U3CfGrlzD2tpsKpnzZlkF/HCF423xEeGuBmyGqs8d6CMdHwMtDsi9Azu2UaOlZn/ZUQEydHATDfdnFLH58DRt9VpB674/BVZBl2IVsLaAWyT4XItGNsuIivfSWJ9C4Bm2Entl37DWtxCddVFBVdHV/iRfKARbSKfmi7csEpDuvGtuvrjKPTe9lwnMqK7VR8eBHD6IMt5zgyfmgKkya06XdLa9y+uhWg6QNo6kGnSJVZ1LMq/te9MC8o=" Jan 27 10:44:12 volumio go-librespot[26266]: time="2026-01-27T10:44:12+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 10:44:13 volumio go-librespot[26266]: time="2026-01-27T10:44:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 10:44:13 volumio go-librespot[26266]: time="2026-01-27T10:44:13+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:13 volumio go-librespot[26266]: time="2026-01-27T10:44:13+07:00" level=debug msg="completed challenge" Jan 27 10:44:13 volumio go-librespot[26266]: time="2026-01-27T10:44:13+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 10:44:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:13 volumio volumio-remote-updater[628]: [2026-01-27 10:44:13] [connect] Successful connection Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "outputs"... Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "albumart"... Jan 27 10:44:13 volumio volumio[26179]: info: Plugin example_plugin is not enabled Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "inputs"... Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "updater_comm"... Jan 27 10:44:13 volumio volumio[26179]: info: Plugin mpdemulation is not enabled Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "rest_api"... Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "websocket"... Jan 27 10:44:13 volumio volumio[26179]: info: Starting Socket.io Server version 1.7.4 Jan 27 10:44:13 volumio volumio[26179]: info: Loading plugin "RoonBridge"... Jan 27 10:44:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:14 volumio volumio[26179]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 10:44:14 volumio volumio[26179]: info: Loading i18n strings for locale en Jan 27 10:44:14 volumio volumio[26179]: Updating browse sources language Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:14 volumio volumio[26287]: Forking 3 albumart workers Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::initPlayerControls Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 10:44:14 volumio volumio[26179]: Express server listening on port 3000 Jan 27 10:44:14 volumio volumio[26179]: [Metrics] WebUI: 16s 62.97ms Jan 27 10:44:14 volumio volumio[26179]: info: CoreStateMachine::resetVolumioState Jan 27 10:44:14 volumio volumio[26179]: info: CoreStateMachine::getcurrentVolume Jan 27 10:44:14 volumio volumio[26179]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:44:14 volumio volumio[26179]: info: Volumio Network Manager: Network status updated: 1 Jan 27 10:44:14 volumio sudo[26330]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 10:44:14 volumio sudo[26330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:14 volumio sudo[26330]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:14 volumio sudo[26332]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 10:44:14 volumio sudo[26332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:14 volumio sudo[26332]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:15 volumio volumio[26179]: info: VolumeController:: Volume=100 Mute =false Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::pushState Jan 27 10:44:15 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::updateTrackBlock Jan 27 10:44:15 volumio volumio[26179]: info: CorePlayQueue::getTrackBlock Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:44:15 volumio volumio-remote-updater[628]: [2026-01-27 10:44:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769485453 101 Jan 27 10:44:15 volumio volumio[26179]: 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 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:15 volumio volumio[26179]: info: Reloading queue from file Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::setRepeat null single undefined Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::pushState Jan 27 10:44:15 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::setRandom null Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::pushState Jan 27 10:44:15 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:15 volumio volumio[26179]: info: Setting Device type: Raspberry PI Jan 27 10:44:15 volumio volumio[26179]: info: Completed loading Core Plugins Jan 27 10:44:15 volumio volumio[26179]: info: Preparing to generate the ALSA configuration file Jan 27 10:44:15 volumio volumio[26179]: info: VolumeController:: Volume=100 Mute =false Jan 27 10:44:15 volumio volumio[26179]: info: CoreStateMachine::pushState Jan 27 10:44:15 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:15 volumio volumio[26179]: info: Asound.conf file unchanged, so no further update is needed Jan 27 10:44:15 volumio volumio[26179]: info: Output device has changed, restarting MPD Jan 27 10:44:15 volumio volumio[26179]: info: Output device has changed, restarting Shairport Sync Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:15 volumio sudo[26348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 10:44:15 volumio sudo[26348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:15 volumio sudo[26350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 10:44:15 volumio sudo[26350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:15 volumio sudo[26350]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:15 volumio sudo[26352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 10:44:15 volumio sudo[26352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:15 volumio volumio[26179]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 10:44:15 volumio volumio[26179]: info: ___________ START PLUGINS ___________ Jan 27 10:44:15 volumio volumio[26179]: info: ControllerMpd::onStart: Initializing MPD Jan 27 10:44:15 volumio volumio[26179]: info: Creating MPD Configuration file Jan 27 10:44:15 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 10:44:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:15 volumio sudo[26348]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:44:15 volumio volumio[26179]: info: [1769485455965] CoreMusicLibrary::Adding element Media Servers Jan 27 10:44:15 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 10:44:16 volumio volumio[26179]: info: UPNP Browser: Client initialized successfully Jan 27 10:44:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 10:44:16 volumio systemd[1]: mpd.service: Consumed 7.365s CPU time. Jan 27 10:44:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 10:44:16 volumio sudo[26361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 10:44:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 10:44:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 10:44:16 volumio sudo[26361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:16 volumio sudo[26361]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:16 volumio sudo[26363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 10:44:16 volumio sudo[26363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 10:44:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 10:44:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 10:44:16 volumio volumio[26179]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 10:44:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 10:44:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 10:44:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 10:44:16 volumio volumio[26179]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:44:16 volumio volumio[26179]: info: [1769485456294] CoreMusicLibrary::Adding element Last_100 Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:44:16 volumio volumio[26179]: info: [1769485456304] CoreMusicLibrary::Adding element Webradio Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:44:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 10:44:16 volumio volumio[26179]: info: Initializing BBC Radios Jan 27 10:44:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 10:44:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 10:44:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:16 volumio go-librespot[26381]: go-librespot daemon starting... Jan 27 10:44:16 volumio go-librespot[26384]: time="2026-01-27T10:44:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:16 volumio go-librespot[26384]: time="2026-01-27T10:44:16+07:00" level=debug msg="app state loaded" Jan 27 10:44:16 volumio go-librespot[26384]: time="2026-01-27T10:44:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:16 volumio volumio[26179]: info: Creating Spotify config file Jan 27 10:44:16 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:16 volumio sudo[26378]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 10:44:16 volumio sudo[26378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 10:44:16 volumio sudo[26378]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+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 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+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 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=info msg="zeroconf server listening on port 40309" Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=debug msg="obtained new client token: AAB057NxKGG83Ktxgg9hDTR8WZ9UJqogI4uS3JtxMcZPTE20UvPRQ1TrMqz3zQetw7YxPGTyu3ZP+EJIcB7yCw2GkcZ/W4X9K4/ZnUaggGirs7J7PWdvEeNw+skKwIcDxu/W2E5JAq0P27qJl5TJ/nsL1bYBl6wyZhRWWxti4jyM2D7yvqTql8/5TVugguFtaGiYs0mNTWbGawvB57+YwkE6tXz2Jgz+GuZL5ZfZan3/tvqSjUxsOItPBCw=" Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=debug msg="completed challenge" Jan 27 10:44:17 volumio go-librespot[26384]: time="2026-01-27T10:44:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:44:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:17 volumio volumio[26297]: Starting albumart workers Jan 27 10:44:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:18 volumio volumio[26179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:44:18 volumio volumio[26179]: info: [1769485458041] CoreMusicLibrary::Adding element YouTube Music Jan 27 10:44:18 volumio volumio[26298]: Starting albumart workers Jan 27 10:44:18 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:18 volumio volumio[26179]: Cannot find translation for source YouTube Music Jan 27 10:44:18 volumio volumio[26179]: info: Volumio Calling Home Jan 27 10:44:18 volumio sudo[26402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 10:44:18 volumio sudo[26402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:18 volumio volumio[26299]: Starting albumart workers Jan 27 10:44:18 volumio sudo[26402]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:18 volumio volumio[26179]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 10:44:18 volumio volumio[26179]: info: Discovery: Found device Volumio Jan 27 10:44:18 volumio volumio[26179]: info: CoreCommandRouter::volumioGetState Jan 27 10:44:18 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:18 volumio volumio[26179]: info: MPD Permissions set Jan 27 10:44:18 volumio volumio[26179]: info: MPD Permissions set Jan 27 10:44:18 volumio volumio[26179]: info: Upmpdcli Daemon Started Jan 27 10:44:18 volumio volumio[26179]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 10:44:18 volumio volumio[26179]: info: Discovery: Found device Volumio Jan 27 10:44:18 volumio volumio[26179]: info: CoreCommandRouter::volumioGetState Jan 27 10:44:18 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:19 volumio volumio[26179]: info: Spotify config file written Jan 27 10:44:19 volumio volumio[26179]: 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 10:44:19 volumio volumio[26179]: info: Volumio called home Jan 27 10:44:19 volumio sudo[26408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:44:19 volumio sudo[26408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:19 volumio go-librespot[26415]: go-librespot daemon starting... Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio sudo[26408]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:19 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:19 volumio go-librespot[26416]: time="2026-01-27T10:44:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:19 volumio go-librespot[26416]: time="2026-01-27T10:44:19+07:00" level=debug msg="app state loaded" Jan 27 10:44:19 volumio volumio[26179]: info: No need to fix Spotify hosts Jan 27 10:44:19 volumio go-librespot[26416]: time="2026-01-27T10:44:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+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 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+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 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=info msg="zeroconf server listening on port 34303" Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=debug msg="obtained new client token: AACxwLmOc4d/YWNdnqlE+WrYXDwmcYD+eQ++xdD7RwDzCjMoyPXRig5VA9UMGSghZ3zP6rbOQ046gPeQMvpJnIEbVcwIvVHo4q50T7LkYJimUQyr9GmasVTQRQXU0CL+IhHI6kBimSnIpdzBbh+x+fAnc7VURyDwWhW2AUpzqetByNlszPZ7NCkCySiMpLDiTQjXfKoaOqjovj3F3hnygmVE0OuC/soTEmxf/h4v1zK0z7qEUtliJKfof8A=" Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=debug msg="completed challenge" Jan 27 10:44:20 volumio go-librespot[26416]: time="2026-01-27T10:44:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:44:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:20 volumio volumio[26179]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 10:44:20 volumio volumio[26179]: SPOTIFY: BQDtS9YkK6CP1n6orTjFq701mcji3SVMf1qK69MqFntG63SvqE9tv6MW_OfT5veZEWbB8PXR3jPRP3IhnjvzGC0HKT7b4HdQ2BDmGieiz-rSsVoTzv6CmBWGcLZiA-aqfx0VtE-JXAia7Z01oURK6LgcGkqHaEyMyxgfgUgevJzZaXWibeSskWB85pTwfattZrQoqurEwLMM1Pbef-B1veH8Zt9lvjU4DFl_T82fBxABV9CB0xk2IycvmYYnIpS528dTCeZS37ISo30dBmCAoyDi738PsGgdWXr52OasZVUQDjze9zH_gx_a Jan 27 10:44:20 volumio volumio[26179]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 10:44:20 volumio volumio[26179]: info: New Spotify access token = BQDtS9YkK6CP1n6orTjFq701mcji3SVMf1qK69MqFntG63SvqE9tv6MW_OfT5veZEWbB8PXR3jPRP3IhnjvzGC0HKT7b4HdQ2BDmGieiz-rSsVoTzv6CmBWGcLZiA-aqfx0VtE-JXAia7Z01oURK6LgcGkqHaEyMyxgfgUgevJzZaXWibeSskWB85pTwfattZrQoqurEwLMM1Pbef-B1veH8Zt9lvjU4DFl_T82fBxABV9CB0xk2IycvmYYnIpS528dTCeZS37ISo30dBmCAoyDi738PsGgdWXr52OasZVUQDjze9zH_gx_a Jan 27 10:44:20 volumio volumio[26179]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 10:44:20 volumio volumio[26179]: info: Starting Shairport Sync Jan 27 10:44:20 volumio volumio[26179]: info: Starting Shairport Sync Jan 27 10:44:20 volumio volumio[26179]: info: Starting Shairport Sync Jan 27 10:44:20 volumio sudo[26447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 10:44:20 volumio sudo[26447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:20 volumio sudo[26453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 10:44:20 volumio sudo[26450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 10:44:20 volumio sudo[26450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:20 volumio sudo[26453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 10:44:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 10:44:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 10:44:21 volumio systemd[1]: shairport-sync.service: Consumed 2.548s CPU time. Jan 27 10:44:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 10:44:21 volumio sudo[26453]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:21 volumio sudo[26450]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:21 volumio sudo[26447]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:21 volumio volumio[26179]: info: Shairport-Sync Started Jan 27 10:44:21 volumio volumio[26179]: Error adding Membership: Error: addMembership EINVAL Jan 27 10:44:21 volumio volumio[26179]: info: Shairport-Sync Started Jan 27 10:44:21 volumio volumio[26179]: info: Shairport-Sync Started Jan 27 10:44:21 volumio volumio[26179]: info: CoreCommandRouter::volumioGetState Jan 27 10:44:21 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:21 volumio volumio[26179]: 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 10:44:21 volumio volumio[26179]: info: Spotify Successfully logged in Jan 27 10:44:21 volumio volumio[26179]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:44:21 volumio volumio[26179]: info: [1769485461625] CoreMusicLibrary::Adding element Spotify Jan 27 10:44:21 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:21 volumio volumio[26179]: Cannot find translation for source YouTube Music Jan 27 10:44:21 volumio volumio[26179]: Cannot find translation for source Spotify Jan 27 10:44:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:22 volumio volumio[26179]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 10:44:22 volumio volumio[26179]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:44:22 volumio volumio[26179]: info: VolumeController:: Volume=100 Mute =false Jan 27 10:44:22 volumio volumio[26179]: info: CoreCommandRouter::volumioGetState Jan 27 10:44:22 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:22 volumio volumio[26179]: info: CoreStateMachine::pushState Jan 27 10:44:22 volumio volumio[26179]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:22 volumio volumio[26179]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:23 volumio volumio[26179]: info: go-librespot daemon successfully initialized Jan 27 10:44:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 10:44:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:23 volumio go-librespot[26488]: go-librespot daemon starting... Jan 27 10:44:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:23 volumio go-librespot[26489]: time="2026-01-27T10:44:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:23 volumio go-librespot[26489]: time="2026-01-27T10:44:23+07:00" level=debug msg="app state loaded" Jan 27 10:44:23 volumio go-librespot[26489]: time="2026-01-27T10:44:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:23 volumio mpd[26400]: 2026-01-27T10:44:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 10:44:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 10:44:24 volumio sudo[26352]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:24 volumio sudo[26363]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:24 volumio volumio[26179]: error: MPD error: The expression evaluated to a falsy value: Jan 27 10:44:24 volumio volumio[26179]: assert.ok(self.idling) Jan 27 10:44:24 volumio volumio[26179]: error: The expression evaluated to a falsy value: Jan 27 10:44:24 volumio volumio[26179]: assert.ok(self.idling) Jan 27 10:44:24 volumio volumio[26179]: info: MPD running with PID26400 Jan 27 10:44:24 volumio volumio[26179]: ,establishing connection Jan 27 10:44:24 volumio volumio[26179]: error: updateQueue error: null Jan 27 10:44:24 volumio volumio[26179]: info: Completed starting Core Plugins Jan 27 10:44:24 volumio volumio[26179]: info: ------------------------------------------- Jan 27 10:44:24 volumio volumio[26179]: info: ----- MyVolumio plugins startup ---- Jan 27 10:44:24 volumio volumio[26179]: info: ------------------------------------------- Jan 27 10:44:24 volumio volumio[26179]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 10:44:24 volumio volumio[26179]: error: updateQueue error: null Jan 27 10:44:24 volumio go-librespot[26489]: time="2026-01-27T10:44:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 10:44:24 volumio go-librespot[26489]: time="2026-01-27T10:44:24+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 10:44:24 volumio go-librespot[26489]: time="2026-01-27T10:44:24+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 10:44:24 volumio go-librespot[26489]: time="2026-01-27T10:44:24+07:00" level=info msg="zeroconf server listening on port 45671" Jan 27 10:44:24 volumio go-librespot[26489]: time="2026-01-27T10:44:24+07:00" level=debug msg="obtained new client token: AACfrEubetltHuTbWbcbU/PzxDmyrdmadjl+VInR7X1jgk2suVpV89yjKlih8h+a2RJbXAle16+UEWoL0tmy/GIc3hdmPnr8F+gxcCpO3WoUg0wU2H+vSwjcwAGxnKja7RpuLq/qjK+sjD5W5FWcYFF+8hleoB2mtZc0O8LI+Akp3IJdujI2pY7/p4rDd21ncbRkFbZfbA3yAAMVPCiFlFM2O4NGRyeNeKPEhR/Ei49B8j9D6Rcn45P0kgo=" Jan 27 10:44:24 volumio go-librespot[26489]: time="2026-01-27T10:44:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:25 volumio go-librespot[26489]: time="2026-01-27T10:44:25+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:25 volumio go-librespot[26489]: time="2026-01-27T10:44:25+07:00" level=debug msg="completed challenge" Jan 27 10:44:25 volumio go-librespot[26489]: time="2026-01-27T10:44:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:44:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:26 volumio volumio[26179]: info: Initializing connection to go-librespot Websocket Jan 27 10:44:26 volumio volumio[26179]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:44:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 10:44:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:28 volumio go-librespot[26500]: go-librespot daemon starting... Jan 27 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+07:00" level=debug msg="app state loaded" Jan 27 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+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 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+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 10:44:28 volumio go-librespot[26501]: time="2026-01-27T10:44:28+07:00" level=info msg="zeroconf server listening on port 39597" Jan 27 10:44:29 volumio go-librespot[26501]: time="2026-01-27T10:44:29+07:00" level=debug msg="obtained new client token: AAAvQggAOQnYIaYU170c4WRUWH8EOzH7YD4+IykLLlqd+9v46ZPm0IU/3pmxEhHvko5a0ER9QzOnVsLT4l8+oJRZAxu+MhsAKyILR5x8WkK7/dnrrqbf12eixZ2TI1bcKmLYTrXR9tqW5fL5CLfZr9kIE6hixdez0gf/7PHRO6FA4FZYEUKHmqAVk0VI57+hRkMPYSK7vEHKWk4/98s3ucJ4r2UiHVgj4KKPJR08gjXV5FIqrZwsssm1" Jan 27 10:44:29 volumio volumio[26179]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 10:44:29 volumio go-librespot[26501]: time="2026-01-27T10:44:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:29 volumio go-librespot[26501]: time="2026-01-27T10:44:29+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:29 volumio go-librespot[26501]: time="2026-01-27T10:44:29+07:00" level=debug msg="completed challenge" Jan 27 10:44:29 volumio go-librespot[26501]: time="2026-01-27T10:44:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:44:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:29 volumio volumio[26179]: info: Initializing connection to go-librespot Websocket Jan 27 10:44:29 volumio volumio[26179]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:44:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 27 10:44:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:32 volumio go-librespot[26508]: go-librespot daemon starting... Jan 27 10:44:32 volumio go-librespot[26509]: time="2026-01-27T10:44:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:32 volumio go-librespot[26509]: time="2026-01-27T10:44:32+07:00" level=debug msg="app state loaded" Jan 27 10:44:32 volumio go-librespot[26509]: time="2026-01-27T10:44:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:32 volumio volumio[26179]: info: Initializing connection to go-librespot Websocket Jan 27 10:44:32 volumio go-librespot[26509]: time="2026-01-27T10:44:32+07:00" level=debug msg="new websocket client" Jan 27 10:44:32 volumio volumio[26179]: info: Connection to go-librespot Websocket established Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 10:44:33 volumio volumio[26179]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=info msg="zeroconf server listening on port 33651" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="obtained new client token: AADl5o4jQEMBHemPebgQ8XRv1MPmgirJ8XBgTXdR+OnI6TIcdbYH9SAbcCxt89QDNc8y0DLEMcMuHKQ/2l5d2Q18xGULCyh+CJK84a2DCyGqXSPvUXKz3iwr5GwFOwTefZPZVohILvBFVDpOyenFNJRc23XSlEU7cP+og4g7gCzQb67fLRSMQCbisofnYI8WMtN1Tvkr12uxgt42krphka3bRUHls5G1yRDAHMDTBt/LNZmGRu8Phki0pMQ=" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44:33+07:00" level=debug msg="completed challenge" Jan 27 10:44:33 volumio go-librespot[26509]: time="2026-01-27T10:44: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 10:44:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:34 volumio volumio[26179]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 10:44:34 volumio volumio[26179]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 10:44:34 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:34 volumio volumio[26179]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:34 volumio volumio[26179]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 10:44:34 volumio volumio[26179]: info: MyVolumio login type: Token Jan 27 10:44:35 volumio volumio[26179]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 10:44:35 volumio volumio[26179]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 10:44:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:36 volumio volumio[26179]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 10:44:36 volumio volumio[26179]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 10:44:36 volumio volumio[26179]: info: Streaming services startup Jan 27 10:44:36 volumio volumio[26179]: info: Starting Streaming Daemon Jan 27 10:44:36 volumio sudo[26533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 10:44:36 volumio sudo[26533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:36 volumio volumio[26179]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 10:44:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 10:44:36 volumio sudo[26533]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:36 volumio volumio[26179]: info: Getting Spotify volume Jan 27 10:44:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:37 volumio go-librespot[26539]: go-librespot daemon starting... Jan 27 10:44:37 volumio volumio[26179]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=debug msg="app state loaded" Jan 27 10:44:37 volumio volumio[26179]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:44:37 volumio volumio[26179]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 10:44:37 volumio volumio[26179]: errno: -111, Jan 27 10:44:37 volumio volumio[26179]: code: 'ECONNREFUSED', Jan 27 10:44:37 volumio volumio[26179]: syscall: 'connect', Jan 27 10:44:37 volumio volumio[26179]: address: '127.0.0.1', Jan 27 10:44:37 volumio volumio[26179]: port: 9879, Jan 27 10:44:37 volumio volumio[26179]: response: undefined Jan 27 10:44:37 volumio volumio[26179]: } Jan 27 10:44:37 volumio volumio[26179]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+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 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+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 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=info msg="zeroconf server listening on port 44231" Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=debug msg="obtained new client token: AAAwW8mzZuo9sAp+3s55TJ6B3x8apgNQ0HZkAYN8lDvMeXDpFbblm8pzV5J4LLP9cLzuMRBHO5XQFYPJJM8m8ArFhneS7s1H6DdDh4OeeuO3cx1EwHZd/PTbFBYPNVjw8zaeUDp396Cqq14mXMDB54/yRLmLte7SrYRhW87vsiX4H1EhTCcWKyM5VW86N4VVC2V2LNC9pKZKOATM4aC1OXbGH7fdR3cVsMlr29BfLePXOp+69Ielzz5M4XE=" Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:37 volumio go-librespot[26540]: time="2026-01-27T10:44:37+07:00" level=debug msg="completed challenge" Jan 27 10:44:38 volumio go-librespot[26540]: time="2026-01-27T10:44:38+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 10:44:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:38 volumio sudo[26561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 10:43' Jan 27 10:44:38 volumio sudo[26561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:38 volumio sudo[26561]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:39 volumio volumio-remote-updater[628]: [2026-01-27 10:44:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 10:44:39 volumio volumio-remote-updater[628]: [2026-01-27 10:44:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 10:44:39 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:39 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 10:44:39 volumio systemd[1]: volumio.service: Consumed 1min 8.202s CPU time. Jan 27 10:44:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 10:44:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 10:44:39 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8421. Jan 27 10:44:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 10:44:39 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 10:44:39 volumio systemd[1]: volumio.service: Consumed 1min 8.202s CPU time. Jan 27 10:44:39 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 10:44:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 10:44:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 10:44:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:41 volumio go-librespot[26588]: go-librespot daemon starting... Jan 27 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+07:00" level=debug msg="app state loaded" Jan 27 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+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 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+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 10:44:41 volumio go-librespot[26589]: time="2026-01-27T10:44:41+07:00" level=info msg="zeroconf server listening on port 46263" Jan 27 10:44:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:42 volumio go-librespot[26589]: time="2026-01-27T10:44:42+07:00" level=debug msg="obtained new client token: AAA0pjbWVPNMEWS5/GVV+4hUOneP43Nuailzw6B+EmCkWRz6OX3/VcGjAPyzKEQDX9CQA7a7YD0injbrPubC8O4UX34at+9FwkJcErKmnh9b7JduxvC5FV91zUucv8MgtzsVqz/qnIVrjHkE/8le8+PFj1LhA1ordIbYC1ybkku4Hs5IRcxZ1/Bs3kPfCc754rR4vrmNW0JOCBuZTL8coYuDWeoW8ddk0rFiFfWZYwarkhhAYZLGzt5/" Jan 27 10:44:42 volumio go-librespot[26589]: time="2026-01-27T10:44:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:42 volumio go-librespot[26589]: time="2026-01-27T10:44:42+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:42 volumio go-librespot[26589]: time="2026-01-27T10:44:42+07:00" level=debug msg="completed challenge" Jan 27 10:44:42 volumio go-librespot[26589]: time="2026-01-27T10:44:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:44:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:42 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:44:42 volumio volumio[26573]: info: ----- Volumio3 ---- Jan 27 10:44:42 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:44:42 volumio volumio[26573]: info: ----- System startup ---- Jan 27 10:44:42 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:44:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:44 volumio volumio-remote-updater[628]: [2026-01-27 10:44:44] [connect] Successful connection Jan 27 10:44:44 volumio volumio[26573]: info: MYVOLUMIO Environment detected Jan 27 10:44:44 volumio volumio[26573]: info: Plugin folders cleanup Jan 27 10:44:44 volumio volumio[26573]: info: Scanning into folder /volumio/app/plugins/ Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category audio_interface Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category miscellanea Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category music_service Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category plugins.json Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category system_controller Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category user_interface Jan 27 10:44:44 volumio volumio[26573]: info: Scanning into folder /data/plugins/ Jan 27 10:44:44 volumio volumio[26573]: info: Scanning category music_service Jan 27 10:44:44 volumio volumio[26573]: info: Plugin folders cleanup completed Jan 27 10:44:44 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:44:44 volumio volumio[26573]: info: ----- Core plugins startup ---- Jan 27 10:44:44 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:44:44 volumio volumio[26573]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 10:44:44 volumio volumio[26573]: info: Adding plugin upnp to MyMusic Plugins Jan 27 10:44:44 volumio volumio[26573]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 10:44:44 volumio volumio[26573]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 10:44:44 volumio volumio[26573]: info: Loading plugins from folder /data/plugins/ Jan 27 10:44:44 volumio volumio[26573]: info: Loading plugin "system"... Jan 27 10:44:44 volumio volumio[26573]: info: Loading plugin "appearance"... Jan 27 10:44:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 27 10:44:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:45 volumio go-librespot[26608]: go-librespot daemon starting... Jan 27 10:44:45 volumio go-librespot[26609]: time="2026-01-27T10:44:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:45 volumio go-librespot[26609]: time="2026-01-27T10:44:45+07:00" level=debug msg="app state loaded" Jan 27 10:44:45 volumio go-librespot[26609]: time="2026-01-27T10:44:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+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 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+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 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+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 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+07:00" level=info msg="zeroconf server listening on port 35133" Jan 27 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+07:00" level=debug msg="obtained new client token: AACn3i6g3oiDQFfgKsELX15Qy5CvdnjpRlwkQFHX9ZqbhXIoc1JKWkl3uVs7AR5MCZLZWzQ9ON4iE/Jw+MabRvzISEFdVMgv4UUAJsu0kLzmCgs24HIuvX4Ig4F81eR/mYzAJeMApEvNd0wlF6p0JJRoiz6Z+6RBWwhHD7yVjz8GhXjPnB41WheZZ0dpFGo8K7iqh36tbSx5Cf9CIF8aEn2UQGOLmjR2jP0p3u6jcQIiluotL6OTSFBnlnw=" Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "network"... Jan 27 10:44:46 volumio volumio[26573]: info: Refreshing Cached IP Addresses Jan 27 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:46 volumio sudo[26617]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 10:44:46 volumio sudo[26617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:46 volumio sudo[26619]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 10:44:46 volumio sudo[26619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "services"... Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "alsa_controller"... Jan 27 10:44:46 volumio sudo[26619]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:46 volumio sudo[26617]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+07:00" level=debug msg="completed challenge" Jan 27 10:44:46 volumio sudo[26628]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 10:44:46 volumio sudo[26628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:46 volumio go-librespot[26609]: time="2026-01-27T10:44:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:44:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:46 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "wizard"... Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "networkfs"... Jan 27 10:44:46 volumio volumio[26573]: info: Starting Udev Watcher for removable devices Jan 27 10:44:46 volumio volumio[26573]: info: Ignoring mount for partition: boot Jan 27 10:44:46 volumio volumio[26573]: info: Ignoring mount for partition: volumio Jan 27 10:44:46 volumio volumio[26573]: info: Ignoring mount for partition: volumio_data Jan 27 10:44:46 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "volumio_command_line_client"... Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "upnp"... Jan 27 10:44:46 volumio volumio[26573]: info: [1769485486923] Starting Upmpd Daemon Jan 27 10:44:46 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "my_music"... Jan 27 10:44:46 volumio volumio[26573]: info: Loading plugin "mpd"... Jan 27 10:44:47 volumio volumio[26573]: info: Loading plugin "upnp_browser"... Jan 27 10:44:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:49 volumio sudo[26628]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 27 10:44:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:50 volumio go-librespot[26650]: go-librespot daemon starting... Jan 27 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+07:00" level=debug msg="app state loaded" Jan 27 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:50 volumio volumio[26573]: info: Starting UPNP Browser Jan 27 10:44:50 volumio volumio[26573]: info: Loading plugin "alarm-clock"... Jan 27 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+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 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+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 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+07:00" level=info msg="zeroconf server listening on port 39235" Jan 27 10:44:50 volumio volumio[26573]: info: Loading plugin "airplay_emulation"... Jan 27 10:44:50 volumio volumio[26573]: info: Starting Shairport Sync Jan 27 10:44:50 volumio volumio[26573]: info: Loading plugin "last_100"... Jan 27 10:44:50 volumio volumio[26573]: info: Loading plugin "webradio"... Jan 27 10:44:50 volumio go-librespot[26651]: time="2026-01-27T10:44:50+07:00" level=debug msg="obtained new client token: AACjpyzmE9I0aD9Qdb6JlANDVx5q/lwhKmjwxJKKXRJ5bOWO3wCzqOQTg6amwDegOsLimXsyha5OJmteOSdwfWgwF0sdtquxk9vbaHnXNpZyaH2edL7ZhMuHBkrja8AnCEowW/88bPITF0Tq6oqOZBf7v8soa4sR0OlNO+xtdcQfM7ULtZKnWXza1JldxnYmhfiUXmcM1zvhCpCiZjpqZvtktAYUQbHpD3RY/G4llqbd5KWCnuadkkiD29Q=" Jan 27 10:44:51 volumio go-librespot[26651]: time="2026-01-27T10:44:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:51 volumio volumio[26573]: info: Loading plugin "i2s_dacs"... Jan 27 10:44:51 volumio volumio[26573]: info: Loading plugin "volumiodiscovery"... Jan 27 10:44:51 volumio go-librespot[26651]: time="2026-01-27T10:44:51+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:51 volumio go-librespot[26651]: time="2026-01-27T10:44:51+07:00" level=debug msg="completed challenge" Jan 27 10:44:51 volumio volumio[26573]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:51 volumio volumio[26573]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:51 volumio volumio[26573]: *** WARNING *** For more information see Jan 27 10:44:51 volumio volumio[26573]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:51 volumio volumio[26573]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:51 volumio volumio[26573]: *** WARNING *** For more information see Jan 27 10:44:51 volumio node[26573]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:51 volumio node[26573]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:51 volumio node[26573]: *** WARNING *** For more information see Jan 27 10:44:51 volumio node[26573]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 10:44:51 volumio node[26573]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 10:44:51 volumio node[26573]: *** WARNING *** For more information see Jan 27 10:44:51 volumio volumio[26573]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 10:44:51 volumio volumio[26573]: info: Discovery: Started advertising with name: Volumio Jan 27 10:44:51 volumio go-librespot[26651]: time="2026-01-27T10:44:51+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 10:44:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:51 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 10:44:51 volumio volumio[26573]: info: Loading plugin "spop"... Jan 27 10:44:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:53 volumio volumio[26573]: info: Loading plugin "ytcr"... Jan 27 10:44:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 27 10:44:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:54 volumio go-librespot[26661]: go-librespot daemon starting... Jan 27 10:44:54 volumio go-librespot[26662]: time="2026-01-27T10:44:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:54 volumio go-librespot[26662]: time="2026-01-27T10:44:54+07:00" level=debug msg="app state loaded" Jan 27 10:44:54 volumio go-librespot[26662]: time="2026-01-27T10:44:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+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 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+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 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+07:00" level=info msg="zeroconf server listening on port 38457" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+07:00" level=debug msg="obtained new client token: AABKnV04pZ1aG4IFrl1VwxqoZmE4apVMtHutPTLxeS8qHFDd2f8ZsbGyquFz+Med/YP2NpUDkrjBLSF14uHPYH6X7397Ugt/RqJpUUehy+IUqR5Kdd/AQKK/pK1oxwKHMoXoH3NhPNcbFn1soYwZJ2l557fmxA05sMUXoUFZkI/RsZDR72nZyQnb2HOO22Y48NePquQBof8OxJR8Mk895X0+q4A9+w8EOWynAA+/4Kc2DLPmlHPW7rnL" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+07:00" level=debug msg="completed keyexchange" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+07:00" level=debug msg="completed challenge" Jan 27 10:44:55 volumio go-librespot[26662]: time="2026-01-27T10:44:55+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 10:44:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:44:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:44:55 volumio volumio[26573]: info: Loading plugin "ytmusic"... Jan 27 10:44:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:56 volumio volumio-remote-updater[628]: [2026-01-27 10:44:56] [connect] Successful connection Jan 27 10:44:56 volumio volumio[26573]: info: Loading plugin "outputs"... Jan 27 10:44:56 volumio volumio[26573]: info: Loading plugin "albumart"... Jan 27 10:44:56 volumio volumio[26573]: info: Plugin example_plugin is not enabled Jan 27 10:44:56 volumio volumio[26573]: info: Loading plugin "inputs"... Jan 27 10:44:56 volumio volumio[26573]: info: Loading plugin "updater_comm"... Jan 27 10:44:57 volumio volumio[26573]: info: Plugin mpdemulation is not enabled Jan 27 10:44:57 volumio volumio[26573]: info: Loading plugin "rest_api"... Jan 27 10:44:57 volumio volumio[26573]: info: Loading plugin "websocket"... Jan 27 10:44:57 volumio volumio[26573]: info: Starting Socket.io Server version 1.7.4 Jan 27 10:44:57 volumio volumio[26573]: info: Loading plugin "RoonBridge"... Jan 27 10:44:57 volumio volumio[26573]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 10:44:57 volumio volumio[26573]: info: Loading i18n strings for locale en Jan 27 10:44:57 volumio volumio[26573]: Updating browse sources language Jan 27 10:44:57 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:57 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 10:44:57 volumio volumio[26573]: info: CoreCommandRouter::initPlayerControls Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: Express server listening on port 3000 Jan 27 10:44:58 volumio volumio[26684]: Forking 3 albumart workers Jan 27 10:44:58 volumio volumio[26573]: [Metrics] WebUI: 16s 39.28ms Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::resetVolumioState Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::getcurrentVolume Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:44:58 volumio sudo[26726]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 10:44:58 volumio sudo[26726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:58 volumio sudo[26726]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:58 volumio sudo[26728]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 10:44:58 volumio sudo[26728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:58 volumio sudo[26728]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:58 volumio volumio[26573]: info: Volumio Network Manager: Network status updated: 1 Jan 27 10:44:58 volumio volumio[26573]: info: VolumeController:: Volume=100 Mute =false Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::pushState Jan 27 10:44:58 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::updateTrackBlock Jan 27 10:44:58 volumio volumio[26573]: info: CorePlayQueue::getTrackBlock Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:44:58 volumio volumio-remote-updater[628]: [2026-01-27 10:44:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769485496 101 Jan 27 10:44:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 27 10:44:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:58 volumio volumio[26573]: 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 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:58 volumio volumio[26573]: info: Reloading queue from file Jan 27 10:44:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:44:58 volumio go-librespot[26737]: go-librespot daemon starting... Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::setRepeat null single undefined Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::pushState Jan 27 10:44:58 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 10:44:58 volumio go-librespot[26742]: time="2026-01-27T10:44:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:44:58 volumio go-librespot[26742]: time="2026-01-27T10:44:58+07:00" level=debug msg="app state loaded" Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:58 volumio go-librespot[26742]: time="2026-01-27T10:44:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::setRandom null Jan 27 10:44:58 volumio volumio[26573]: info: CoreStateMachine::pushState Jan 27 10:44:58 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:58 volumio volumio[26573]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:58 volumio volumio[26573]: info: Setting Device type: Raspberry PI Jan 27 10:44:59 volumio volumio[26573]: info: Completed loading Core Plugins Jan 27 10:44:59 volumio volumio[26573]: info: Preparing to generate the ALSA configuration file Jan 27 10:44:59 volumio volumio[26573]: info: VolumeController:: Volume=100 Mute =false Jan 27 10:44:59 volumio volumio[26573]: info: CoreStateMachine::pushState Jan 27 10:44:59 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::volumioPushState Jan 27 10:44:59 volumio volumio[26573]: info: Asound.conf file unchanged, so no further update is needed Jan 27 10:44:59 volumio volumio[26573]: info: Output device has changed, restarting MPD Jan 27 10:44:59 volumio sudo[26753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 10:44:59 volumio sudo[26753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:59 volumio volumio[26573]: info: Output device has changed, restarting Shairport Sync Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:59 volumio sudo[26755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 10:44:59 volumio sudo[26755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:59 volumio sudo[26758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 10:44:59 volumio sudo[26755]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:59 volumio sudo[26758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:59 volumio volumio[26573]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 10:44:59 volumio volumio[26573]: info: ___________ START PLUGINS ___________ Jan 27 10:44:59 volumio volumio[26573]: info: ControllerMpd::onStart: Initializing MPD Jan 27 10:44:59 volumio volumio[26573]: info: Creating MPD Configuration file Jan 27 10:44:59 volumio go-librespot[26742]: time="2026-01-27T10:44:59+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 10:44:59 volumio go-librespot[26742]: time="2026-01-27T10:44:59+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 10:44:59 volumio go-librespot[26742]: time="2026-01-27T10:44:59+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 10:44:59 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:44:59 volumio volumio[26573]: info: [1769485499585] CoreMusicLibrary::Adding element Media Servers Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:44:59 volumio sudo[26753]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:59 volumio go-librespot[26742]: time="2026-01-27T10:44:59+07:00" level=info msg="zeroconf server listening on port 40745" Jan 27 10:44:59 volumio sudo[26766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 10:44:59 volumio sudo[26766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:59 volumio sudo[26766]: pam_unix(sudo:session): session closed for user root Jan 27 10:44:59 volumio volumio[26573]: info: UPNP Browser: Client initialized successfully Jan 27 10:44:59 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 10:44:59 volumio sudo[26768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 10:44:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 10:44:59 volumio systemd[1]: mpd.service: Consumed 7.383s CPU time. Jan 27 10:44:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 10:44:59 volumio sudo[26768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:44:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 10:44:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:59 volumio go-librespot[26742]: time="2026-01-27T10:44:59+07:00" level=debug msg="obtained new client token: AACzOL66RWmBdbrZ01KQRXgs2RlZJrkZL5Mka18kOo7ZSAFDU1mfIZMS/o8eDATwHPFPWu2AebYlm6sEnszzig2Di+bCePK0oB0VzN9ElWg6KdNGQShwTkN0/L29O0G31tdnW3s5tq2zmQwgj+HNnuDO1CaHzievnS3czDwpM1oF0JbTZ8LvvrnOSOGc97afZ2S3rR5ASYw7i+GMiHHGMh3dTjq697Nd0d8YqNyXp2x8MqLQBn2rJtEOkIY=" Jan 27 10:44:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 10:44:59 volumio volumio[26573]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:44:59 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:44:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 10:44:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:44:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:44:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:44:59 volumio go-librespot[26742]: time="2026-01-27T10:44:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:45:00 volumio volumio[26573]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 10:45:00 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 10:45:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 10:45:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:45:00 volumio volumio[26573]: info: [1769485500041] CoreMusicLibrary::Adding element Last_100 Jan 27 10:45:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 10:45:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:45:00 volumio volumio[26573]: info: [1769485500072] CoreMusicLibrary::Adding element Webradio Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:45:00 volumio go-librespot[26742]: time="2026-01-27T10:45:00+07:00" level=debug msg="completed keyexchange" Jan 27 10:45:00 volumio go-librespot[26742]: time="2026-01-27T10:45:00+07:00" level=debug msg="completed challenge" Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:45:00 volumio volumio[26573]: info: Initializing BBC Radios Jan 27 10:45:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 10:45:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 10:45:00 volumio go-librespot[26742]: time="2026-01-27T10:45:00+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 10:45:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:45:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:45:00 volumio volumio[26573]: info: Creating Spotify config file Jan 27 10:45:00 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:00 volumio sudo[26784]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 10:45:00 volumio sudo[26784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 10:45:00 volumio sudo[26784]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:01 volumio volumio[26699]: Starting albumart workers Jan 27 10:45:01 volumio volumio[26698]: Starting albumart workers Jan 27 10:45:01 volumio volumio[26695]: Starting albumart workers Jan 27 10:45:01 volumio volumio[26573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:45:01 volumio volumio[26573]: info: [1769485501711] CoreMusicLibrary::Adding element YouTube Music Jan 27 10:45:01 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:45:01 volumio volumio[26573]: Cannot find translation for source YouTube Music Jan 27 10:45:01 volumio volumio[26573]: info: Volumio Calling Home Jan 27 10:45:01 volumio sudo[26799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 10:45:01 volumio sudo[26799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:02 volumio sudo[26799]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:02 volumio volumio[26573]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 10:45:02 volumio volumio[26573]: info: Discovery: Found device Volumio Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::volumioGetState Jan 27 10:45:02 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:02 volumio volumio[26573]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 10:45:02 volumio volumio[26573]: info: Discovery: Found device Volumio Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::volumioGetState Jan 27 10:45:02 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:02 volumio volumio[26573]: info: MPD Permissions set Jan 27 10:45:02 volumio volumio[26573]: info: MPD Permissions set Jan 27 10:45:02 volumio volumio[26573]: info: Upmpdcli Daemon Started Jan 27 10:45:02 volumio volumio[26573]: info: Spotify config file written Jan 27 10:45:02 volumio volumio[26573]: 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 10:45:02 volumio sudo[26806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:45:02 volumio sudo[26806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:45:02 volumio volumio[26573]: info: Volumio called home Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:45:02 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:45:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:02 volumio volumio[26573]: info: No need to fix Spotify hosts Jan 27 10:45:02 volumio go-librespot[26813]: go-librespot daemon starting... Jan 27 10:45:03 volumio sudo[26806]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+07:00" level=debug msg="app state loaded" Jan 27 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+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 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+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 10:45:03 volumio go-librespot[26819]: time="2026-01-27T10:45:03+07:00" level=info msg="zeroconf server listening on port 42595" Jan 27 10:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:04 volumio go-librespot[26819]: time="2026-01-27T10:45:04+07:00" level=debug msg="obtained new client token: AABwT7ScfJG6iQ7BUPAB2zy1c0/lstFRK1zPOFt9fOGyB45t12Zi7AdWhVo87E68OoJTUVV/JdiHrMW3tvnl0iGVUdIohMPQ8fbnS3cCa9CzgUPxnZRdlWnr/giXzo0Fare00deHnLyHNB6+qoqvvWjeHxdlTxLh4+jw+SpJpUss3QHVWKACHexoMw5zOu28eXPQZIK0fxYwTpo0wsWC3lxaIdYSxu2cWs8cPCFUbpT1ucVvaSVTN4vJSj4=" Jan 27 10:45:04 volumio go-librespot[26819]: time="2026-01-27T10:45:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:45:04 volumio go-librespot[26819]: time="2026-01-27T10:45:04+07:00" level=debug msg="completed keyexchange" Jan 27 10:45:04 volumio go-librespot[26819]: time="2026-01-27T10:45:04+07:00" level=debug msg="completed challenge" Jan 27 10:45:04 volumio volumio[26573]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 10:45:04 volumio volumio[26573]: SPOTIFY: BQAr0mg_b1ailCHBE3Fu8eM1vzyk_sCdJzQOfreXS0y0oH_NiHZkB1DGj0y6ORAZd0k7pdpOv4_0Rp_h4sFBFOv051QJRxqaR4sSOBa5_WZigIQuG8cKNK1pCX_nMchKG8Dr-IR2jcnk11KOnI8-RjQSvSRWxsEDBctLuWECK7XM6cIt-5HtAkYnBLlZf3gLIKIG1UTsOrfDrT-TK05TOgN3mNzCmCcCSC4V__Ffs4KY654Vq-4N_V3m_bm3cfffmAwOEJUSLcISRD33qdjxe5nHRVrfMh1HS6DEXR3pm_Ba7XE8n5YBNN2P Jan 27 10:45:04 volumio volumio[26573]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 10:45:04 volumio volumio[26573]: info: New Spotify access token = BQAr0mg_b1ailCHBE3Fu8eM1vzyk_sCdJzQOfreXS0y0oH_NiHZkB1DGj0y6ORAZd0k7pdpOv4_0Rp_h4sFBFOv051QJRxqaR4sSOBa5_WZigIQuG8cKNK1pCX_nMchKG8Dr-IR2jcnk11KOnI8-RjQSvSRWxsEDBctLuWECK7XM6cIt-5HtAkYnBLlZf3gLIKIG1UTsOrfDrT-TK05TOgN3mNzCmCcCSC4V__Ffs4KY654Vq-4N_V3m_bm3cfffmAwOEJUSLcISRD33qdjxe5nHRVrfMh1HS6DEXR3pm_Ba7XE8n5YBNN2P Jan 27 10:45:04 volumio volumio[26573]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 10:45:04 volumio go-librespot[26819]: time="2026-01-27T10:45:04+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 10:45:04 volumio volumio[26573]: info: Starting Shairport Sync Jan 27 10:45:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:45:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:45:04 volumio volumio[26573]: info: Starting Shairport Sync Jan 27 10:45:04 volumio volumio[26573]: info: Starting Shairport Sync Jan 27 10:45:04 volumio sudo[26848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 10:45:04 volumio sudo[26848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:45:04 volumio sudo[26846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 10:45:04 volumio sudo[26846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:45:04 volumio sudo[26851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 10:45:04 volumio sudo[26851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:45:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 10:45:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 10:45:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 10:45:04 volumio systemd[1]: shairport-sync.service: Consumed 2.340s CPU time. Jan 27 10:45:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 10:45:04 volumio sudo[26846]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:04 volumio sudo[26851]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:04 volumio sudo[26848]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:04 volumio volumio[26573]: info: Shairport-Sync Started Jan 27 10:45:04 volumio volumio[26573]: Error adding Membership: Error: addMembership EINVAL Jan 27 10:45:04 volumio volumio[26573]: info: Shairport-Sync Started Jan 27 10:45:04 volumio volumio[26573]: info: Shairport-Sync Started Jan 27 10:45:04 volumio volumio[26573]: info: CoreCommandRouter::volumioGetState Jan 27 10:45:04 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:05 volumio volumio[26573]: 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 10:45:05 volumio volumio[26573]: info: Spotify Successfully logged in Jan 27 10:45:05 volumio volumio[26573]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:45:05 volumio volumio[26573]: info: [1769485505247] CoreMusicLibrary::Adding element Spotify Jan 27 10:45:05 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:45:05 volumio volumio[26573]: Cannot find translation for source YouTube Music Jan 27 10:45:05 volumio volumio[26573]: Cannot find translation for source Spotify Jan 27 10:45:05 volumio volumio[26573]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 10:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:05 volumio volumio[26573]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 10:45:06 volumio volumio[26573]: info: VolumeController:: Volume=100 Mute =false Jan 27 10:45:06 volumio volumio[26573]: info: CoreCommandRouter::volumioGetState Jan 27 10:45:06 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:06 volumio volumio[26573]: info: CoreStateMachine::pushState Jan 27 10:45:06 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:06 volumio volumio[26573]: info: CoreCommandRouter::volumioPushState Jan 27 10:45:07 volumio volumio[26573]: info: go-librespot daemon successfully initialized Jan 27 10:45:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 27 10:45:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:07 volumio go-librespot[26885]: go-librespot daemon starting... Jan 27 10:45:07 volumio go-librespot[26886]: time="2026-01-27T10:45:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:45:07 volumio go-librespot[26886]: time="2026-01-27T10:45:07+07:00" level=debug msg="app state loaded" Jan 27 10:45:07 volumio go-librespot[26886]: time="2026-01-27T10:45:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:45:07 volumio mpd[26797]: 2026-01-27T10:45:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 10:45:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 10:45:07 volumio sudo[26758]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:07 volumio sudo[26768]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:08 volumio volumio[26573]: error: MPD error: The expression evaluated to a falsy value: Jan 27 10:45:08 volumio volumio[26573]: assert.ok(self.idling) Jan 27 10:45:08 volumio volumio[26573]: error: The expression evaluated to a falsy value: Jan 27 10:45:08 volumio volumio[26573]: assert.ok(self.idling) Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+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 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+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 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+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 10:45:08 volumio volumio[26573]: info: MPD running with PID26797 Jan 27 10:45:08 volumio volumio[26573]: ,establishing connection Jan 27 10:45:08 volumio volumio[26573]: error: updateQueue error: null Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+07:00" level=info msg="zeroconf server listening on port 39397" Jan 27 10:45:08 volumio volumio[26573]: info: Completed starting Core Plugins Jan 27 10:45:08 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:45:08 volumio volumio[26573]: info: ----- MyVolumio plugins startup ---- Jan 27 10:45:08 volumio volumio[26573]: info: ------------------------------------------- Jan 27 10:45:08 volumio volumio[26573]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 10:45:08 volumio volumio[26573]: error: updateQueue error: null Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+07:00" level=debug msg="obtained new client token: AADDZUNaN3icSm7w8dvdKh3ajs02bEj3f8sBvVDqFwL4rULQ6jBsERbPhaP3ann5Rn6Ddp4wpI51zX5nUXFB/87DM0PX2aGUniOkoCYQUTD6GJHeEtPT62IqTUleWRLdpPNBGoWXokTDt2SqZZvOU0hauMqWf+OjxARHI81Dgycgr5Uzp09YtX+uyIRuy4C7CtahFuK6B4bAvMkVqxefYt2LNXV57Ef6QMSlbZXiXb0xdKYqbzyBUe+Qygk=" Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+07:00" level=debug msg="completed keyexchange" Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+07:00" level=debug msg="completed challenge" Jan 27 10:45:08 volumio go-librespot[26886]: time="2026-01-27T10:45:08+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 10:45:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:45:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:10 volumio volumio[26573]: info: Initializing connection to go-librespot Websocket Jan 27 10:45:10 volumio volumio[26573]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:45:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 27 10:45:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:11 volumio go-librespot[26901]: go-librespot daemon starting... Jan 27 10:45:11 volumio go-librespot[26902]: time="2026-01-27T10:45:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:45:11 volumio go-librespot[26902]: time="2026-01-27T10:45:11+07:00" level=debug msg="app state loaded" Jan 27 10:45:11 volumio go-librespot[26902]: time="2026-01-27T10:45:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+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 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+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 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+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 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+07:00" level=info msg="zeroconf server listening on port 46519" Jan 27 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+07:00" level=debug msg="obtained new client token: AADUWvNGdKXPmoM3p8Ag29GwAN4mQii442rAU3oBu/BF1h5FKE25IRxL25kLlAi31j0tzdmYk3yxJCs+RXvPAI5cZ1zuxS3+EUJVP2frra/25R0y3DZnYBd5tzqSMCom0RjEZJmXM3oDrO0fr67E8Mrpngkf3hACg2GVsm9P+PmFsFddTFlDGqvxlYd3YrolIF39r6pmGydHh/Dho/KOiG9YfL+W6Y0j2TUWNYk1dIiJfy34G1Rgg15wtOE=" Jan 27 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+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 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+07:00" level=debug msg="completed keyexchange" Jan 27 10:45:12 volumio go-librespot[26902]: time="2026-01-27T10:45:12+07:00" level=debug msg="completed challenge" Jan 27 10:45:13 volumio volumio[26573]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 10:45:13 volumio go-librespot[26902]: time="2026-01-27T10:45:13+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 10:45:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:45:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:45:13 volumio volumio[26573]: info: Initializing connection to go-librespot Websocket Jan 27 10:45:13 volumio volumio[26573]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 27 10:45:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:16 volumio go-librespot[26910]: go-librespot daemon starting... Jan 27 10:45:16 volumio volumio[26573]: info: Initializing connection to go-librespot Websocket Jan 27 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+07:00" level=debug msg="app state loaded" Jan 27 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+07:00" level=debug msg="new websocket client" Jan 27 10:45:16 volumio volumio[26573]: info: Connection to go-librespot Websocket established Jan 27 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+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 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+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 10:45:16 volumio go-librespot[26911]: time="2026-01-27T10:45:16+07:00" level=info msg="zeroconf server listening on port 44221" Jan 27 10:45:17 volumio go-librespot[26911]: time="2026-01-27T10:45:17+07:00" level=debug msg="obtained new client token: AABnhQhq2qAt1RIZ22pdp0AV9m6Y5QJRAqkNvA9gcqHsvTdUkq0mY3gGbdZu8DHNyXa64zU6tc7SXMAjwfGm5cFQ1T4vRcJqbfBl1VNVso+9+eiUISxt8h5enFf0oVnbP6RTCxRvJMZSk5WIP2leaCNsjUtS2Tq+mUED+rnw4dpIHDST+lRFmymokrRwqanRwpvNF71GhfiFyFxg7ZXImZ6xcHtCHsJZQ6bnU8HSdWWqjDfG3dEFEyBh" Jan 27 10:45:17 volumio go-librespot[26911]: time="2026-01-27T10:45:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 10:45:17 volumio volumio[26573]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 10:45:17 volumio go-librespot[26911]: time="2026-01-27T10:45:17+07:00" level=debug msg="completed keyexchange" Jan 27 10:45:17 volumio go-librespot[26911]: time="2026-01-27T10:45:17+07:00" level=debug msg="completed challenge" Jan 27 10:45:17 volumio go-librespot[26911]: time="2026-01-27T10:45:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:45:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:45:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:19 volumio volumio[26573]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 10:45:19 volumio volumio[26573]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 10:45:19 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:45:19 volumio volumio[26573]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 10:45:19 volumio volumio[26573]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 10:45:19 volumio volumio[26573]: info: MyVolumio login type: Token Jan 27 10:45:19 volumio volumio[26573]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 10:45:19 volumio volumio[26573]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 10:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 27 10:45:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:45:20 volumio go-librespot[26932]: go-librespot daemon starting... Jan 27 10:45:20 volumio go-librespot[26933]: time="2026-01-27T10:45:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 10:45:20 volumio go-librespot[26933]: time="2026-01-27T10:45:20+07:00" level=debug msg="app state loaded" Jan 27 10:45:20 volumio go-librespot[26933]: time="2026-01-27T10:45:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:45:20 volumio volumio[26573]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 10:45:20 volumio volumio[26573]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 10:45:20 volumio volumio[26573]: info: Streaming services startup Jan 27 10:45:20 volumio volumio[26573]: info: Starting Streaming Daemon Jan 27 10:45:21 volumio sudo[26942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 10:45:21 volumio sudo[26942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:45:21 volumio volumio[26573]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 10:45:21 volumio sudo[26942]: pam_unix(sudo:session): session closed for user root Jan 27 10:45:21 volumio volumio[26573]: info: Getting Spotify volume Jan 27 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+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 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+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 10:45:21 volumio volumio[26573]: info: Connection to go-librespot Websocket closed Jan 27 10:45:21 volumio volumio[26573]: error: Cannot start Volumio Streaming Daemon Jan 27 10:45:21 volumio volumio[26573]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 10:45:21 volumio volumio[26573]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+07:00" level=info msg="zeroconf server listening on port 38055" Jan 27 10:45:21 volumio volumio[26573]: 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 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+07:00" level=debug msg="obtained new client token: AACY8ryO8kjtW0zbfLuridQ1NP6W7WRjO0ezAEENKAlFatBpWUVD8EmxenKr5/plvQzvHC+Sz9y1WE79h3oBtNRlcDftabAel2Yps2rVeGR0AXkU78dZAp9omeQJV1o1sJS0hxTax+Xg2aLTeAVLh+cNofR6pupJDM6PiyxhDbgl5uPgHp+c86lDH07qvXCyb7v77gviC8JrklrZZwon0J3AcnTgJO1S+0Ec79CE//UE9iLmhGJhvyu4Cro=" Jan 27 10:45:21 volumio volumio[26573]: info: CoreCommandRouter::volumioGetState Jan 27 10:45:21 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 10:45:21 volumio volumio[26573]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 10:45:21 volumio volumio[26573]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 10:45:21 volumio volumio[26573]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 10:45:21 volumio volumio[26573]: info: Aligning Spotify Volume to Volumio Volume Jan 27 10:45:21 volumio volumio[26573]: info: CoreCommandRouter::volumioGetState Jan 27 10:45:21 volumio volumio[26573]: info: CorePlayQueue::getTrack 0 Jan 27 10:45:21 volumio volumio[26573]: info: Setting Spotify Volume from Volumio: 100 Jan 27 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+07:00" level=debug msg="completed keyexchange" Jan 27 10:45:21 volumio go-librespot[26933]: time="2026-01-27T10:45:21+07:00" level=debug msg="completed challenge" Jan 27 10:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 10:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 10:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 10:45:22 volumio go-librespot[26933]: time="2026-01-27T10:45:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 10:45:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 10:45:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 10:45:22 volumio volumio[26573]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:45:22 volumio volumio[26573]: Error: socket hang up Jan 27 10:45:22 volumio volumio[26573]: at connResetException (node:internal/errors:720:14) Jan 27 10:45:22 volumio volumio[26573]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 10:45:22 volumio volumio[26573]: at Socket.emit (node:events:526:35) Jan 27 10:45:22 volumio volumio[26573]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 10:45:22 volumio volumio[26573]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 10:45:22 volumio volumio[26573]: code: 'ECONNRESET', Jan 27 10:45:22 volumio volumio[26573]: response: undefined Jan 27 10:45:22 volumio volumio[26573]: } Jan 27 10:45:22 volumio volumio[26573]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:45:23 volumio sudo[26963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 10:44' Jan 27 10:45:23 volumio sudo[26963]: 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"