Jan 27 16:58:00 volumio volumio-remote-updater[628]: [2026-01-27 16:58:00] [connect] Successful connection Jan 27 16:58:01 volumio volumio[23603]: info: MYVOLUMIO Environment detected Jan 27 16:58:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:01 volumio volumio[23603]: info: Plugin folders cleanup Jan 27 16:58:01 volumio volumio[23603]: info: Scanning into folder /volumio/app/plugins/ Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category audio_interface Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category miscellanea Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category music_service Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category plugins.json Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category system_controller Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category user_interface Jan 27 16:58:01 volumio volumio[23603]: info: Scanning into folder /data/plugins/ Jan 27 16:58:01 volumio volumio[23603]: info: Scanning category music_service Jan 27 16:58:01 volumio volumio[23603]: info: Plugin folders cleanup completed Jan 27 16:58:01 volumio volumio[23603]: info: ------------------------------------------- Jan 27 16:58:01 volumio volumio[23603]: info: ----- Core plugins startup ---- Jan 27 16:58:01 volumio volumio[23603]: info: ------------------------------------------- Jan 27 16:58:01 volumio volumio[23603]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 16:58:01 volumio volumio[23603]: info: Adding plugin upnp to MyMusic Plugins Jan 27 16:58:01 volumio volumio[23603]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 16:58:01 volumio volumio[23603]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 16:58:01 volumio volumio[23603]: info: Loading plugins from folder /data/plugins/ Jan 27 16:58:01 volumio volumio[23603]: info: Loading plugin "system"... Jan 27 16:58:01 volumio volumio[23603]: info: Loading plugin "appearance"... Jan 27 16:58:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 27 16:58:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:03 volumio go-librespot[23639]: go-librespot daemon starting... Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+07:00" level=debug msg="app state loaded" Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "network"... Jan 27 16:58:03 volumio volumio[23603]: info: Refreshing Cached IP Addresses Jan 27 16:58:03 volumio sudo[23647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 16:58:03 volumio sudo[23647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:03 volumio sudo[23649]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 16:58:03 volumio sudo[23649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:03 volumio sudo[23647]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:03 volumio sudo[23649]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "services"... Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "alsa_controller"... Jan 27 16:58:03 volumio sudo[23658]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 16:58:03 volumio sudo[23658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:03 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "wizard"... Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "networkfs"... Jan 27 16:58:03 volumio volumio[23603]: info: Starting Udev Watcher for removable devices Jan 27 16:58:03 volumio volumio[23603]: info: Ignoring mount for partition: boot Jan 27 16:58:03 volumio volumio[23603]: info: Ignoring mount for partition: volumio Jan 27 16:58:03 volumio volumio[23603]: info: Ignoring mount for partition: volumio_data Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+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 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+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 16:58:03 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "volumio_command_line_client"... Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "upnp"... Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+07:00" level=info msg="zeroconf server listening on port 39291" Jan 27 16:58:03 volumio volumio[23603]: info: [1769507883738] Starting Upmpd Daemon Jan 27 16:58:03 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "my_music"... Jan 27 16:58:03 volumio volumio[23603]: info: Loading plugin "mpd"... Jan 27 16:58:03 volumio go-librespot[23640]: time="2026-01-27T16:58:03+07:00" level=debug msg="obtained new client token: AABsVvho5MqwdPH/K8Ycy+KCUZfGFq5VaR2GUlpkldtikpJ3k1/9T5ALt3EFXcwAgBLHesQHMbseo+5mdgsKLENdq1CbnkMz9wMceMjt11nisgD8HKg6cTUh2IxpbSz0HngKhaqWKm1JQBOY+4jEeD2pD7lqmEGxk2rTEf+zcOnYnF9ZRD3LBffDHmR+EJLLEVcg+1i2WkVU1Ga9fdYP3fe8Z3mvQKOOs9sjpUriRyNgYSgoic4XUijst8U=" Jan 27 16:58:04 volumio go-librespot[23640]: time="2026-01-27T16:58:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:04 volumio volumio[23603]: info: Loading plugin "upnp_browser"... Jan 27 16:58:04 volumio go-librespot[23640]: time="2026-01-27T16:58:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:38936->104.199.241.202:4070: read: connection reset by peer" Jan 27 16:58:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:06 volumio sudo[23658]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:07 volumio volumio[23603]: info: Starting UPNP Browser Jan 27 16:58:07 volumio volumio[23603]: info: Loading plugin "alarm-clock"... Jan 27 16:58:07 volumio volumio[23603]: info: Loading plugin "airplay_emulation"... Jan 27 16:58:07 volumio volumio[23603]: info: Starting Shairport Sync Jan 27 16:58:07 volumio volumio[23603]: info: Loading plugin "last_100"... Jan 27 16:58:07 volumio volumio[23603]: info: Loading plugin "webradio"... Jan 27 16:58:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jan 27 16:58:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:07 volumio go-librespot[23682]: go-librespot daemon starting... Jan 27 16:58:07 volumio go-librespot[23683]: time="2026-01-27T16:58:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:07 volumio go-librespot[23683]: time="2026-01-27T16:58:07+07:00" level=debug msg="app state loaded" Jan 27 16:58:07 volumio go-librespot[23683]: time="2026-01-27T16:58:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:07 volumio volumio[23603]: info: Loading plugin "i2s_dacs"... Jan 27 16:58:07 volumio volumio[23603]: info: Loading plugin "volumiodiscovery"... Jan 27 16:58:07 volumio volumio[23603]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:07 volumio volumio[23603]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:07 volumio volumio[23603]: *** WARNING *** For more information see Jan 27 16:58:07 volumio volumio[23603]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:07 volumio volumio[23603]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:07 volumio volumio[23603]: *** WARNING *** For more information see Jan 27 16:58:07 volumio node[23603]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:07 volumio node[23603]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:07 volumio node[23603]: *** WARNING *** For more information see Jan 27 16:58:07 volumio node[23603]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:07 volumio node[23603]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:07 volumio node[23603]: *** WARNING *** For more information see Jan 27 16:58:07 volumio volumio[23603]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 16:58:08 volumio volumio[23603]: info: Discovery: Started advertising with name: Volumio Jan 27 16:58:08 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:58:08 volumio volumio[23603]: info: Loading plugin "spop"... Jan 27 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58:08+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 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58:08+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 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58:08+07:00" level=info msg="zeroconf server listening on port 45423" Jan 27 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58:08+07:00" level=debug msg="obtained new client token: AABAQ+s3brrOWl3C8aY2wujwg9HxCKhpi8cC+VDaBvXinNqJINm9eoV9lgejoZmURRVvl+vvqsItvXKs/Drja8TTJlsIBeIFKvW+uBYi5ve+HYgauwvsK21M8O6oNIqIpahC32xv+guLpR2xEXfJYqxle7nqG1UcuaN0oPSu5/PGWki13jybYqmwNr4qGCr6HEElb4rHCFQCH2/Nc+A0k5YW7eV1xOGnPQySymPb2x9kNsMlsU3sJNduAU4=" Jan 27 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:08 volumio go-librespot[23683]: time="2026-01-27T16:58:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 16:58:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:09 volumio volumio[23603]: info: Loading plugin "ytcr"... Jan 27 16:58:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Jan 27 16:58:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:12 volumio go-librespot[23693]: go-librespot daemon starting... Jan 27 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+07:00" level=debug msg="app state loaded" Jan 27 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:12 volumio volumio[23603]: info: Loading plugin "ytmusic"... Jan 27 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+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 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+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 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+07:00" level=info msg="zeroconf server listening on port 45867" Jan 27 16:58:12 volumio go-librespot[23694]: time="2026-01-27T16:58:12+07:00" level=debug msg="obtained new client token: AAD0bAtPZe19M1+S/AR1/kEiZmqTa4/DDqwQEaYdCVD7NRgtEKyhIkzd866JyB9GK3Y/C3vE/PmOJrVvF4Qy3ghr5jUUZX/uYd5eLbMPywwpQcJkIZgZsEXGXGtZDJ0TL25IMdJDFfhTdsqYAZbHL6ZMLZJzOT0ctLeywAqL6wMhJDiS51DtppNk0U4qfleQwzsKfPXmwBcJ5dkb0L8rrLN4du8thlxHn4X6f/6wI19wdGgSHcoj6xe9YlM=" Jan 27 16:58:13 volumio go-librespot[23694]: time="2026-01-27T16:58:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:13 volumio go-librespot[23694]: time="2026-01-27T16:58:13+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:13 volumio go-librespot[23694]: time="2026-01-27T16:58:13+07:00" level=debug msg="completed challenge" Jan 27 16:58:13 volumio go-librespot[23694]: time="2026-01-27T16:58: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 16:58:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:13 volumio volumio-remote-updater[628]: [2026-01-27 16:58:13] [connect] Successful connection Jan 27 16:58:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "outputs"... Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "albumart"... Jan 27 16:58:13 volumio volumio[23603]: info: Plugin example_plugin is not enabled Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "inputs"... Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "updater_comm"... Jan 27 16:58:13 volumio volumio[23603]: info: Plugin mpdemulation is not enabled Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "rest_api"... Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "websocket"... Jan 27 16:58:13 volumio volumio[23603]: info: Starting Socket.io Server version 1.7.4 Jan 27 16:58:13 volumio volumio[23603]: info: Loading plugin "RoonBridge"... Jan 27 16:58:14 volumio volumio[23603]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 16:58:14 volumio volumio[23603]: info: Loading i18n strings for locale en Jan 27 16:58:14 volumio volumio[23603]: Updating browse sources language Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:14 volumio volumio[23715]: Forking 3 albumart workers Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::initPlayerControls Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:58:14 volumio volumio[23603]: Express server listening on port 3000 Jan 27 16:58:14 volumio volumio[23603]: [Metrics] WebUI: 16s 68.80ms Jan 27 16:58:14 volumio volumio[23603]: info: CoreStateMachine::resetVolumioState Jan 27 16:58:14 volumio volumio[23603]: info: CoreStateMachine::getcurrentVolume Jan 27 16:58:14 volumio volumio[23603]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:58:15 volumio sudo[23757]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 16:58:15 volumio sudo[23757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:15 volumio sudo[23757]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:15 volumio sudo[23759]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 16:58:15 volumio sudo[23759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:15 volumio sudo[23759]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:15 volumio volumio[23603]: info: Volumio Network Manager: Network status updated: 1 Jan 27 16:58:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:15 volumio volumio[23603]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::pushState Jan 27 16:58:15 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::updateTrackBlock Jan 27 16:58:15 volumio volumio[23603]: info: CorePlayQueue::getTrackBlock Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:58:15 volumio volumio-remote-updater[628]: [2026-01-27 16:58:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769507893 101 Jan 27 16:58:15 volumio volumio[23603]: 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 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:15 volumio volumio[23603]: info: Reloading queue from file Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::setRepeat null single undefined Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::pushState Jan 27 16:58:15 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::setRandom null Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::pushState Jan 27 16:58:15 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:15 volumio volumio[23603]: info: Setting Device type: Raspberry PI Jan 27 16:58:15 volumio volumio[23603]: info: Completed loading Core Plugins Jan 27 16:58:15 volumio volumio[23603]: info: Preparing to generate the ALSA configuration file Jan 27 16:58:15 volumio volumio[23603]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:58:15 volumio volumio[23603]: info: CoreStateMachine::pushState Jan 27 16:58:15 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:15 volumio volumio[23603]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:15 volumio volumio[23603]: info: Asound.conf file unchanged, so no further update is needed Jan 27 16:58:15 volumio volumio[23603]: info: Output device has changed, restarting MPD Jan 27 16:58:15 volumio volumio[23603]: info: Output device has changed, restarting Shairport Sync Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:16 volumio sudo[23776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 16:58:16 volumio sudo[23776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:16 volumio sudo[23779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 16:58:16 volumio sudo[23779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:16 volumio sudo[23779]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:16 volumio sudo[23780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 16:58:16 volumio volumio[23603]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:58:16 volumio sudo[23780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:16 volumio volumio[23603]: info: ___________ START PLUGINS ___________ Jan 27 16:58:16 volumio volumio[23603]: info: ControllerMpd::onStart: Initializing MPD Jan 27 16:58:16 volumio volumio[23603]: info: Creating MPD Configuration file Jan 27 16:58:16 volumio sudo[23776]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:16 volumio volumio[23603]: info: [1769507896226] CoreMusicLibrary::Adding element Media Servers Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:16 volumio sudo[23789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 16:58:16 volumio sudo[23789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:16 volumio sudo[23789]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Jan 27 16:58:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:16 volumio sudo[23791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 16:58:16 volumio sudo[23791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:16 volumio volumio[23603]: info: UPNP Browser: Client initialized successfully Jan 27 16:58:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 16:58:16 volumio go-librespot[23793]: go-librespot daemon starting... Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:16 volumio go-librespot[23795]: time="2026-01-27T16:58:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:16 volumio go-librespot[23795]: time="2026-01-27T16:58:16+07:00" level=debug msg="app state loaded" Jan 27 16:58:16 volumio go-librespot[23795]: time="2026-01-27T16:58:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 16:58:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 16:58:16 volumio systemd[1]: mpd.service: Consumed 7.328s CPU time. Jan 27 16:58:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 16:58:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 16:58:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 16:58:16 volumio volumio[23603]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 16:58:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 16:58:16 volumio volumio[23603]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:16 volumio volumio[23603]: info: [1769507896732] CoreMusicLibrary::Adding element Last_100 Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:16 volumio volumio[23603]: info: [1769507896742] CoreMusicLibrary::Adding element Webradio Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:16 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:58:16 volumio volumio[23603]: info: Initializing BBC Radios Jan 27 16:58:17 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:58:17 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:17 volumio volumio[23603]: info: Creating Spotify config file Jan 27 16:58:17 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:17 volumio sudo[23811]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 16:58:17 volumio sudo[23811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 16:58:17 volumio sudo[23811]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58:17+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 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58:17+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 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58:17+07:00" level=info msg="zeroconf server listening on port 33127" Jan 27 16:58:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58:17+07:00" level=debug msg="obtained new client token: AADFkumVMPvK6J25TbYznOyr0ZRf9WBvgJKXaw1rVqCcjl8ozylAf74QBQR/AdYt3D41Lho+BFWgWj6zo70ryYT+GMqFpSU6OuojXWfMt0uCgP9G2/CiULjzXdVz+wT4qQyqvfnHW7OA0ztTlL3OMg39Hrv6iGK9mGPFfW3EY/aaffZRC6vi1VemY8YU69bSD9pABdjuGr9SW9aKUKfayKM2HZlcpcNJn7jQSPUshR315BcKz987+TnWW2k=" Jan 27 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:17 volumio go-librespot[23795]: time="2026-01-27T16:58:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 16:58:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:17 volumio volumio[23726]: Starting albumart workers Jan 27 16:58:18 volumio volumio[23727]: Starting albumart workers Jan 27 16:58:18 volumio volumio[23725]: Starting albumart workers Jan 27 16:58:18 volumio volumio[23603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:18 volumio volumio[23603]: info: [1769507898553] CoreMusicLibrary::Adding element YouTube Music Jan 27 16:58:18 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:18 volumio volumio[23603]: Cannot find translation for source YouTube Music Jan 27 16:58:18 volumio volumio[23603]: info: Volumio Calling Home Jan 27 16:58:18 volumio sudo[23831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 16:58:18 volumio sudo[23831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:19 volumio sudo[23831]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:19 volumio volumio[23603]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 16:58:19 volumio volumio[23603]: info: Discovery: Found device Volumio Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::volumioGetState Jan 27 16:58:19 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:19 volumio volumio[23603]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 16:58:19 volumio volumio[23603]: info: Discovery: Found device Volumio Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::volumioGetState Jan 27 16:58:19 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:19 volumio volumio[23603]: info: MPD Permissions set Jan 27 16:58:19 volumio volumio[23603]: info: MPD Permissions set Jan 27 16:58:19 volumio volumio[23603]: info: Upmpdcli Daemon Started Jan 27 16:58:19 volumio volumio[23603]: info: Volumio called home Jan 27 16:58:19 volumio volumio[23603]: info: Spotify config file written Jan 27 16:58:19 volumio volumio[23603]: 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 16:58:19 volumio sudo[23843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 16:58:19 volumio sudo[23843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:19 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:20 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:20 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:20 volumio volumio[23603]: info: No need to fix Spotify hosts Jan 27 16:58:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:20 volumio go-librespot[23861]: go-librespot daemon starting... Jan 27 16:58:20 volumio sudo[23843]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58:20+07:00" level=debug msg="app state loaded" Jan 27 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58: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 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58: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 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58: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 16:58:20 volumio go-librespot[23862]: time="2026-01-27T16:58:20+07:00" level=info msg="zeroconf server listening on port 39281" Jan 27 16:58:21 volumio volumio[23603]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 16:58:21 volumio volumio[23603]: SPOTIFY: BQAFc_Bkb46HHdKq7DRFbnrgdoP7RnW4UdEeIBcU8GST8_WXPx1X0ctcV7IgsbkB3NzRDoSs9WnKoO2_tsDCTNZy7DgLDWGtZMhUrUr5El3t6HV88rSySJXf7uOG9zxSLfokPA8CANQUn-BytmgRWFhJ4gli8Q3aBvOcGLv9T7CP6-FJWzAeMEtBTbIq9aAmgKrbTM8DLNhOLxtFwXemvgFJz_d46iaagzDg5K9l3jCumPz45ops8F95jE9jhE0JLl6QQ7WfGErgixMraIcPmrCqrzy_u0jNBw7pVteqH_cFbS8fmbp27SXf Jan 27 16:58:21 volumio volumio[23603]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 16:58:21 volumio volumio[23603]: info: New Spotify access token = BQAFc_Bkb46HHdKq7DRFbnrgdoP7RnW4UdEeIBcU8GST8_WXPx1X0ctcV7IgsbkB3NzRDoSs9WnKoO2_tsDCTNZy7DgLDWGtZMhUrUr5El3t6HV88rSySJXf7uOG9zxSLfokPA8CANQUn-BytmgRWFhJ4gli8Q3aBvOcGLv9T7CP6-FJWzAeMEtBTbIq9aAmgKrbTM8DLNhOLxtFwXemvgFJz_d46iaagzDg5K9l3jCumPz45ops8F95jE9jhE0JLl6QQ7WfGErgixMraIcPmrCqrzy_u0jNBw7pVteqH_cFbS8fmbp27SXf Jan 27 16:58:21 volumio volumio[23603]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 16:58:21 volumio go-librespot[23862]: time="2026-01-27T16:58:21+07:00" level=debug msg="obtained new client token: AAB1Wbun9sLne3RYsI+S6whSXVHKeVNt34xDySYgkz/G/KTVPAbWXN5icGSZUBPoNJ0UEk2vcRm+w9aSfAtq8ZnAY/QSb/hoBXOWW1Zt09xL/3neVrLiUfcszC4gut4hVVETqNc48jBb4IDkg2OErV7c1NJChwM7AreV3wF47tV5wJrEUv/s3ZmV/UP7PLdF1B5ILhbQAsYAdVoHe2MWsrU026TpuUtxfyn2lloIoJeZvM2/QHlTJTITDgY=" Jan 27 16:58:21 volumio volumio[23603]: info: Starting Shairport Sync Jan 27 16:58:21 volumio volumio[23603]: info: Starting Shairport Sync Jan 27 16:58:21 volumio volumio[23603]: info: Starting Shairport Sync Jan 27 16:58:21 volumio sudo[23877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:58:21 volumio sudo[23877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:21 volumio go-librespot[23862]: time="2026-01-27T16:58:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:21 volumio sudo[23881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:58:21 volumio sudo[23881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:21 volumio go-librespot[23862]: time="2026-01-27T16:58:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 16:58:21 volumio sudo[23879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:58:21 volumio sudo[23879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 16:58:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 16:58:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:58:21 volumio systemd[1]: shairport-sync.service: Consumed 2.543s CPU time. Jan 27 16:58:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:58:21 volumio sudo[23877]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 16:58:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 16:58:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:58:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:58:21 volumio sudo[23879]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:21 volumio sudo[23881]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:21 volumio volumio[23603]: info: Shairport-Sync Started Jan 27 16:58:21 volumio volumio[23603]: Error adding Membership: Error: addMembership EINVAL Jan 27 16:58:21 volumio volumio[23603]: info: Shairport-Sync Started Jan 27 16:58:21 volumio volumio[23603]: info: Shairport-Sync Started Jan 27 16:58:21 volumio volumio[23603]: info: CoreCommandRouter::volumioGetState Jan 27 16:58:21 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:21 volumio volumio[23603]: 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 16:58:21 volumio volumio[23603]: info: Spotify Successfully logged in Jan 27 16:58:21 volumio volumio[23603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:21 volumio volumio[23603]: info: [1769507901981] CoreMusicLibrary::Adding element Spotify Jan 27 16:58:21 volumio volumio[23603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:21 volumio volumio[23603]: Cannot find translation for source YouTube Music Jan 27 16:58:21 volumio volumio[23603]: Cannot find translation for source Spotify Jan 27 16:58:22 volumio volumio[23603]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 16:58:22 volumio volumio[23603]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:58:22 volumio volumio[23603]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:58:22 volumio volumio[23603]: info: CoreCommandRouter::volumioGetState Jan 27 16:58:22 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:22 volumio volumio[23603]: info: CoreStateMachine::pushState Jan 27 16:58:22 volumio volumio[23603]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:22 volumio volumio[23603]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:23 volumio volumio[23603]: info: go-librespot daemon successfully initialized Jan 27 16:58:24 volumio mpd[23828]: 2026-01-27T16:58:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 16:58:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Jan 27 16:58:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 16:58:24 volumio sudo[23780]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:24 volumio sudo[23791]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:24 volumio go-librespot[23919]: go-librespot daemon starting... Jan 27 16:58:24 volumio go-librespot[23922]: time="2026-01-27T16:58:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:24 volumio go-librespot[23922]: time="2026-01-27T16:58:24+07:00" level=debug msg="app state loaded" Jan 27 16:58:24 volumio go-librespot[23922]: time="2026-01-27T16:58:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:24 volumio volumio[23603]: error: MPD error: The expression evaluated to a falsy value: Jan 27 16:58:24 volumio volumio[23603]: assert.ok(self.idling) Jan 27 16:58:24 volumio volumio[23603]: error: The expression evaluated to a falsy value: Jan 27 16:58:24 volumio volumio[23603]: assert.ok(self.idling) Jan 27 16:58:24 volumio volumio[23603]: error: updateQueue error: null Jan 27 16:58:24 volumio volumio[23603]: info: MPD running with PID23828 Jan 27 16:58:24 volumio volumio[23603]: ,establishing connection Jan 27 16:58:24 volumio volumio[23603]: info: Completed starting Core Plugins Jan 27 16:58:24 volumio volumio[23603]: info: ------------------------------------------- Jan 27 16:58:24 volumio volumio[23603]: info: ----- MyVolumio plugins startup ---- Jan 27 16:58:24 volumio volumio[23603]: info: ------------------------------------------- Jan 27 16:58:24 volumio volumio[23603]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 16:58:24 volumio volumio[23603]: error: updateQueue error: null Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+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 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+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 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+07:00" level=info msg="zeroconf server listening on port 32809" Jan 27 16:58:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+07:00" level=debug msg="obtained new client token: AACQM47dK82in9qDYEibxO4aCx856scwqJKjAPthSCS0+8GRukFp60jAavrUETF20nP7wYk1BcZSlMY7VGTQ1F8GPMNTCf48O9EAavkH96WkXaSfLfhDFyLkerwJ+OmDOW64oHR3Frg0Ta7bn9vwDDUNI5J/D1SAvRGNmO/0TXU1WVOjQE5M/ZgmFVWfkvBJht+h5rdVSu4Qbhr7Rp89TcobFOKx2qP5xnbsaglKBQPKEZfhXdYV/IIxVAY=" Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58:25+07:00" level=debug msg="completed challenge" Jan 27 16:58:25 volumio go-librespot[23922]: time="2026-01-27T16:58: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 16:58:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:26 volumio volumio[23603]: info: Initializing connection to go-librespot Websocket Jan 27 16:58:26 volumio volumio[23603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 16:58:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Jan 27 16:58:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:29 volumio go-librespot[23930]: go-librespot daemon starting... Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=debug msg="app state loaded" Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:29 volumio volumio[23603]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+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 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+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 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=info msg="zeroconf server listening on port 36541" Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=debug msg="obtained new client token: AACtKl5e1mFdmSJuxdhQ38/Ya/kzWgdiOrAgbMpLiu/QBm9PTmHwIcphX8jsFy4c5jgORa8eIxwacDwevKZKQ3rRqlnXRxfa3oaabyXte5ITcGEzuTymS21OXq+4sY2YCv88F5ghk5LcuOEKR5+UPQFZ6h5RZa1JaKIoX0zcZqXZ3OALJN6v5jP+K6IESquGhrZ2GnzqyqWNhhjwSiVPkaAhm00fRHeTIh1A8ymRbYoBeALr1z+OWDvl9C0=" Jan 27 16:58:29 volumio volumio[23603]: info: Initializing connection to go-librespot Websocket Jan 27 16:58:29 volumio go-librespot[23931]: time="2026-01-27T16:58:29+07:00" level=debug msg="new websocket client" Jan 27 16:58:30 volumio volumio[23603]: info: Connection to go-librespot Websocket established Jan 27 16:58:30 volumio go-librespot[23931]: time="2026-01-27T16:58:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:30 volumio go-librespot[23931]: time="2026-01-27T16:58:30+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:30 volumio go-librespot[23931]: time="2026-01-27T16:58:30+07:00" level=debug msg="completed challenge" Jan 27 16:58:30 volumio go-librespot[23931]: time="2026-01-27T16:58:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:58:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:30 volumio volumio[23603]: info: Connection to go-librespot Websocket closed Jan 27 16:58:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:33 volumio volumio[23603]: info: Getting Spotify volume Jan 27 16:58:33 volumio volumio[23603]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 16:58:33 volumio volumio[23603]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 16:58:33 volumio volumio[23603]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 16:58:33 volumio volumio[23603]: errno: -111, Jan 27 16:58:33 volumio volumio[23603]: code: 'ECONNREFUSED', Jan 27 16:58:33 volumio volumio[23603]: syscall: 'connect', Jan 27 16:58:33 volumio volumio[23603]: address: '127.0.0.1', Jan 27 16:58:33 volumio volumio[23603]: port: 9879, Jan 27 16:58:33 volumio volumio[23603]: response: undefined Jan 27 16:58:33 volumio volumio[23603]: } Jan 27 16:58:33 volumio volumio[23603]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 16:58:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Jan 27 16:58:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:33 volumio go-librespot[23949]: go-librespot daemon starting... Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=debug msg="app state loaded" Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:58:33 volumio go-librespot[23950]: time="2026-01-27T16:58:33+07:00" level=info msg="zeroconf server listening on port 41565" Jan 27 16:58:34 volumio go-librespot[23950]: time="2026-01-27T16:58:34+07:00" level=debug msg="obtained new client token: AAABlwGSTnEMsU9Uc7V4gmRJDGwffCD4X2X9e7vL9TXckNvsGzsoEhk5mQmTI/seMSkYXbmXEkajgDJjQwRcYpmY558VIQO2wp0cNIG7xmDC8o5UZyjUS0ZHS3xoLmZ3p09aXPK4d/m1B6v1ZZZSdpZmYAFh5w2+MhQDCKcmJw8371HxJdRrAZu2HWKWdiSpodj/khHnw54YoiTv2vo6gdp9cXKGSYC0s8HAE+oJgmD9YEr9SuX/ZmEO" Jan 27 16:58:34 volumio go-librespot[23950]: time="2026-01-27T16:58:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:34 volumio go-librespot[23950]: time="2026-01-27T16:58:34+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:34 volumio go-librespot[23950]: time="2026-01-27T16:58:34+07:00" level=debug msg="completed challenge" Jan 27 16:58:34 volumio go-librespot[23950]: time="2026-01-27T16:58:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:58:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:34 volumio sudo[23975]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 16:57' Jan 27 16:58:34 volumio sudo[23975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:35 volumio sudo[23975]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:35 volumio volumio-remote-updater[628]: [2026-01-27 16:58:35] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 16:58:35 volumio volumio-remote-updater[628]: [2026-01-27 16:58:35] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 16:58:35 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:35 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 16:58:35 volumio systemd[1]: volumio.service: Consumed 1min 770ms CPU time. Jan 27 16:58:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:35 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 16:58:35 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 16:58:35 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8860. Jan 27 16:58:35 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 16:58:35 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 16:58:35 volumio systemd[1]: volumio.service: Consumed 1min 770ms CPU time. Jan 27 16:58:35 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 16:58:35 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 16:58:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Jan 27 16:58:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:37 volumio go-librespot[24006]: go-librespot daemon starting... Jan 27 16:58:37 volumio go-librespot[24007]: time="2026-01-27T16:58:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:37 volumio go-librespot[24007]: time="2026-01-27T16:58:37+07:00" level=debug msg="app state loaded" Jan 27 16:58:37 volumio go-librespot[24007]: time="2026-01-27T16:58:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+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 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+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 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+07:00" level=info msg="zeroconf server listening on port 43563" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+07:00" level=debug msg="obtained new client token: AADRZPjLAPBUL/IDMwZDhE77EF3D/XHVeIXH4H6WMC+Dvrxf77AkrjzYG8X6jCAC7x6eWJfYdbFDLtKNV5a/aTuvEe0FhqMS70kXnLCWnlTpzsDQzgJvzKXcf1vCia9vGYCEZwFDvqeZD1AFWevMwI/mqEbcUDxpuVDFvu6C1b5vf+BeABMG1Uv5ws627bm69hazo6o6YW6wgP4I7a4rLlzEnKWY2Rxu4CY68ipWaYV4kD7QPxEqkB4/mi8=" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58:38+07:00" level=debug msg="completed challenge" Jan 27 16:58:38 volumio go-librespot[24007]: time="2026-01-27T16:58: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 16:58:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:39 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:58:39 volumio volumio[23990]: info: ----- Volumio3 ---- Jan 27 16:58:39 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:58:39 volumio volumio[23990]: info: ----- System startup ---- Jan 27 16:58:39 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:58:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:40 volumio volumio-remote-updater[628]: [2026-01-27 16:58:40] [connect] Successful connection Jan 27 16:58:40 volumio volumio[23990]: info: MYVOLUMIO Environment detected Jan 27 16:58:40 volumio volumio[23990]: info: Plugin folders cleanup Jan 27 16:58:40 volumio volumio[23990]: info: Scanning into folder /volumio/app/plugins/ Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category audio_interface Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category miscellanea Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category music_service Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category plugins.json Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category system_controller Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category user_interface Jan 27 16:58:40 volumio volumio[23990]: info: Scanning into folder /data/plugins/ Jan 27 16:58:40 volumio volumio[23990]: info: Scanning category music_service Jan 27 16:58:40 volumio volumio[23990]: info: Plugin folders cleanup completed Jan 27 16:58:40 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:58:40 volumio volumio[23990]: info: ----- Core plugins startup ---- Jan 27 16:58:40 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:58:40 volumio volumio[23990]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 16:58:40 volumio volumio[23990]: info: Adding plugin upnp to MyMusic Plugins Jan 27 16:58:40 volumio volumio[23990]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 16:58:40 volumio volumio[23990]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 16:58:40 volumio volumio[23990]: info: Loading plugins from folder /data/plugins/ Jan 27 16:58:40 volumio volumio[23990]: info: Loading plugin "system"... Jan 27 16:58:40 volumio volumio[23990]: info: Loading plugin "appearance"... Jan 27 16:58:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Jan 27 16:58:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:42 volumio go-librespot[24026]: go-librespot daemon starting... Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+07:00" level=debug msg="app state loaded" Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:42 volumio volumio[23990]: info: Loading plugin "network"... Jan 27 16:58:42 volumio volumio[23990]: info: Refreshing Cached IP Addresses Jan 27 16:58:42 volumio sudo[24035]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 16:58:42 volumio sudo[24035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+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 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+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 16:58:42 volumio sudo[24037]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 16:58:42 volumio sudo[24037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:42 volumio volumio[23990]: info: Loading plugin "services"... Jan 27 16:58:42 volumio sudo[24035]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+07:00" level=info msg="zeroconf server listening on port 34837" Jan 27 16:58:42 volumio volumio[23990]: info: Loading plugin "alsa_controller"... Jan 27 16:58:42 volumio sudo[24037]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:42 volumio sudo[24045]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 16:58:42 volumio sudo[24045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:42 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:58:42 volumio volumio[23990]: info: Loading plugin "wizard"... Jan 27 16:58:42 volumio volumio[23990]: info: Loading plugin "networkfs"... Jan 27 16:58:42 volumio volumio[23990]: info: Starting Udev Watcher for removable devices Jan 27 16:58:42 volumio go-librespot[24027]: time="2026-01-27T16:58:42+07:00" level=debug msg="obtained new client token: AAAGDQFjUP7ggj1lz++hoI7Pu9raFk6jeuW47zbzAKkAXZon9tvSBC646HwBfcvtPnq1muACmFbVo5qG2gTgfFhX2PTC9WyfzmZG4OkJy1ceq08YcoyddJSiB4y+Udl4FfSOh1bYF8fJrip14KuWI1zkAm7kbjtcXvNgtjnXhxAA6kIQBkK21TLEuJoMqc0cebXyxYmel618kWq2XwQHjz8ClYCloBj2Y9ZzKVCPlF4LgH9tN7SuNV2Ps0Q=" Jan 27 16:58:42 volumio volumio[23990]: info: Ignoring mount for partition: boot Jan 27 16:58:42 volumio volumio[23990]: info: Ignoring mount for partition: volumio Jan 27 16:58:42 volumio volumio[23990]: info: Ignoring mount for partition: volumio_data Jan 27 16:58:42 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:58:42 volumio volumio[23990]: info: Loading plugin "volumio_command_line_client"... Jan 27 16:58:43 volumio volumio[23990]: info: Loading plugin "upnp"... Jan 27 16:58:43 volumio volumio[23990]: info: [1769507923012] Starting Upmpd Daemon Jan 27 16:58:43 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:58:43 volumio volumio[23990]: info: Loading plugin "my_music"... Jan 27 16:58:43 volumio volumio[23990]: info: Loading plugin "mpd"... Jan 27 16:58:43 volumio go-librespot[24027]: time="2026-01-27T16:58:43+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 16:58:43 volumio go-librespot[24027]: time="2026-01-27T16:58:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 16:58:43 volumio go-librespot[24027]: time="2026-01-27T16:58:43+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:43 volumio go-librespot[24027]: time="2026-01-27T16:58:43+07:00" level=debug msg="completed challenge" Jan 27 16:58:43 volumio go-librespot[24027]: time="2026-01-27T16:58:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:58:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:43 volumio volumio[23990]: info: Loading plugin "upnp_browser"... Jan 27 16:58:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:45 volumio sudo[24045]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Jan 27 16:58:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:46 volumio go-librespot[24069]: go-librespot daemon starting... Jan 27 16:58:46 volumio volumio[23990]: info: Starting UPNP Browser Jan 27 16:58:46 volumio volumio[23990]: info: Loading plugin "alarm-clock"... Jan 27 16:58:46 volumio go-librespot[24070]: time="2026-01-27T16:58:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:46 volumio go-librespot[24070]: time="2026-01-27T16:58:46+07:00" level=debug msg="app state loaded" Jan 27 16:58:46 volumio go-librespot[24070]: time="2026-01-27T16:58:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:46 volumio volumio[23990]: info: Loading plugin "airplay_emulation"... Jan 27 16:58:46 volumio volumio[23990]: info: Starting Shairport Sync Jan 27 16:58:46 volumio volumio[23990]: info: Loading plugin "last_100"... Jan 27 16:58:46 volumio volumio[23990]: info: Loading plugin "webradio"... Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+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 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+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 16:58:47 volumio volumio[23990]: info: Loading plugin "i2s_dacs"... Jan 27 16:58:47 volumio volumio[23990]: info: Loading plugin "volumiodiscovery"... Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=info msg="zeroconf server listening on port 39927" Jan 27 16:58:47 volumio volumio[23990]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:47 volumio volumio[23990]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:47 volumio volumio[23990]: *** WARNING *** For more information see Jan 27 16:58:47 volumio volumio[23990]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:47 volumio volumio[23990]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:47 volumio volumio[23990]: *** WARNING *** For more information see Jan 27 16:58:47 volumio node[23990]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:47 volumio node[23990]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:47 volumio node[23990]: *** WARNING *** For more information see Jan 27 16:58:47 volumio node[23990]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 16:58:47 volumio node[23990]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:58:47 volumio node[23990]: *** WARNING *** For more information see Jan 27 16:58:47 volumio volumio[23990]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 16:58:47 volumio volumio[23990]: info: Discovery: Started advertising with name: Volumio Jan 27 16:58:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:47 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:58:47 volumio volumio[23990]: info: Loading plugin "spop"... Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=debug msg="obtained new client token: AACftdzECQrtu1tPd2bn7H0tF6N31xN1NkV6yNd6iMbClhAiRZI0ttIGEsez85kSUCu4Vyfw8QW+W+oGveCGqCoxyYeZEERLlRfuT4UdpcHrtVgy4asCgc5M/Zjwtp9AlDfaurA00me52ZOAjrj8YKW/41fgDM3Ykj9+7oEJe4IbUQ1NqqteoGeYQS6ojfeRVq2qgWkkrm+yfnrwxSUHbYCfQ6inx654aOrtwA3WAxZLuGQ4Vx+lKUG6tl8=" Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=debug msg="completed challenge" Jan 27 16:58:47 volumio go-librespot[24070]: time="2026-01-27T16:58:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:58:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:49 volumio volumio[23990]: info: Loading plugin "ytcr"... Jan 27 16:58:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Jan 27 16:58:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:51 volumio go-librespot[24080]: go-librespot daemon starting... Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=debug msg="app state loaded" Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=info msg="zeroconf server listening on port 45709" Jan 27 16:58:51 volumio volumio[23990]: info: Loading plugin "ytmusic"... Jan 27 16:58:51 volumio go-librespot[24081]: time="2026-01-27T16:58:51+07:00" level=debug msg="obtained new client token: AAANlslMCrgD8FnJdIAQpaTnds9d1g0QQjmfRho90C9wgvrq3haGo3y+N7HyOiaDZGsYWH84sW6qZCCRS6sn5tPXgEtTCkadrjnZ/vezS1ffXNwsUhUlK+hE+IqIgZuoIgjKve/xr6wsVagRQyAYBy3Hij4kR4qPU1xX5dtMoTfY4VBelx8VVECl7RYqe7DneCelYXYOW8jbtpJ/BLpDvw4LhuIbGJn6du5GI9uHe1MoVEwjl2PQ/bL1QO4=" Jan 27 16:58:52 volumio go-librespot[24081]: time="2026-01-27T16:58:52+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 16:58:52 volumio go-librespot[24081]: time="2026-01-27T16:58:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 16:58:52 volumio go-librespot[24081]: time="2026-01-27T16:58:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 16:58:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:52 volumio volumio-remote-updater[628]: [2026-01-27 16:58:52] [connect] Successful connection Jan 27 16:58:52 volumio volumio[23990]: info: Loading plugin "outputs"... Jan 27 16:58:52 volumio volumio[23990]: info: Loading plugin "albumart"... Jan 27 16:58:52 volumio volumio[23990]: info: Plugin example_plugin is not enabled Jan 27 16:58:52 volumio volumio[23990]: info: Loading plugin "inputs"... Jan 27 16:58:52 volumio volumio[23990]: info: Loading plugin "updater_comm"... Jan 27 16:58:53 volumio volumio[23990]: info: Plugin mpdemulation is not enabled Jan 27 16:58:53 volumio volumio[23990]: info: Loading plugin "rest_api"... Jan 27 16:58:53 volumio volumio[23990]: info: Loading plugin "websocket"... Jan 27 16:58:53 volumio volumio[23990]: info: Starting Socket.io Server version 1.7.4 Jan 27 16:58:53 volumio volumio[23990]: info: Loading plugin "RoonBridge"... Jan 27 16:58:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:53 volumio volumio[23990]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 16:58:53 volumio volumio[23990]: info: Loading i18n strings for locale en Jan 27 16:58:53 volumio volumio[23990]: Updating browse sources language Jan 27 16:58:53 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:54 volumio volumio[24102]: Forking 3 albumart workers Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::initPlayerControls Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: Express server listening on port 3000 Jan 27 16:58:54 volumio volumio[23990]: [Metrics] WebUI: 16s 24.07ms Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::resetVolumioState Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::getcurrentVolume Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:58:54 volumio volumio[23990]: info: Volumio Network Manager: Network status updated: 1 Jan 27 16:58:54 volumio sudo[24146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 16:58:54 volumio sudo[24144]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 16:58:54 volumio sudo[24144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:54 volumio sudo[24146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:54 volumio sudo[24144]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:54 volumio sudo[24146]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:54 volumio volumio[23990]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::pushState Jan 27 16:58:54 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::updateTrackBlock Jan 27 16:58:54 volumio volumio[23990]: info: CorePlayQueue::getTrackBlock Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:58:54 volumio volumio-remote-updater[628]: [2026-01-27 16:58:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769507932 101 Jan 27 16:58:54 volumio volumio[23990]: 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 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:54 volumio volumio[23990]: info: Reloading queue from file Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::setRepeat null single undefined Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::pushState Jan 27 16:58:54 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::setRandom null Jan 27 16:58:54 volumio volumio[23990]: info: CoreStateMachine::pushState Jan 27 16:58:54 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:54 volumio volumio[23990]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:54 volumio volumio[23990]: info: Setting Device type: Raspberry PI Jan 27 16:58:55 volumio volumio[23990]: info: Completed loading Core Plugins Jan 27 16:58:55 volumio volumio[23990]: info: Preparing to generate the ALSA configuration file Jan 27 16:58:55 volumio volumio[23990]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:58:55 volumio volumio[23990]: info: CoreStateMachine::pushState Jan 27 16:58:55 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::volumioPushState Jan 27 16:58:55 volumio volumio[23990]: info: Asound.conf file unchanged, so no further update is needed Jan 27 16:58:55 volumio volumio[23990]: info: Output device has changed, restarting MPD Jan 27 16:58:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Jan 27 16:58:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:55 volumio sudo[24163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 16:58:55 volumio volumio[23990]: info: Output device has changed, restarting Shairport Sync Jan 27 16:58:55 volumio sudo[24163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:55 volumio sudo[24165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 16:58:55 volumio sudo[24165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:55 volumio go-librespot[24166]: go-librespot daemon starting... Jan 27 16:58:55 volumio sudo[24165]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:55 volumio sudo[24168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 16:58:55 volumio sudo[24168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:55 volumio volumio[23990]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:58:55 volumio volumio[23990]: info: ___________ START PLUGINS ___________ Jan 27 16:58:55 volumio go-librespot[24174]: time="2026-01-27T16:58:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:55 volumio go-librespot[24174]: time="2026-01-27T16:58:55+07:00" level=debug msg="app state loaded" Jan 27 16:58:55 volumio go-librespot[24174]: time="2026-01-27T16:58:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:55 volumio sudo[24163]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:55 volumio volumio[23990]: info: ControllerMpd::onStart: Initializing MPD Jan 27 16:58:55 volumio volumio[23990]: info: Creating MPD Configuration file Jan 27 16:58:55 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:55 volumio volumio[23990]: info: [1769507935640] CoreMusicLibrary::Adding element Media Servers Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:55 volumio volumio[23990]: info: UPNP Browser: Client initialized successfully Jan 27 16:58:55 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 16:58:55 volumio sudo[24183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 16:58:55 volumio sudo[24183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 16:58:55 volumio systemd[1]: mpd.service: Consumed 7.348s CPU time. Jan 27 16:58:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 16:58:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 16:58:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 16:58:55 volumio sudo[24183]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:55 volumio sudo[24185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 16:58:55 volumio sudo[24185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:55 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 16:58:55 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 16:58:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 16:58:55 volumio volumio[23990]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:58:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 16:58:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 16:58:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 16:58:56 volumio volumio[23990]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 16:58:56 volumio volumio[23990]: info: [1769507936086] CoreMusicLibrary::Adding element Last_100 Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:56 volumio volumio[23990]: info: [1769507936128] CoreMusicLibrary::Adding element Webradio Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=info msg="zeroconf server listening on port 41045" Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:58:56 volumio volumio[23990]: info: Initializing BBC Radios Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:56 volumio volumio[23990]: info: Creating Spotify config file Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="obtained new client token: AACPJFe7hIQ7hz3KA4EoaO/gvx9FjYp2euA9ii6MO44JGUv/qvorFWqh7029LBERmlur1hSM6cr1zMLNw6sd61DyhsAYPqlkDDh/nIF53V4t0o1Mhl3zNJH0GcABUjP3LXeUIMrDRq3smXDDHWRcRQLBvZN4HHur6gmW2TGgNqxwt+qBrUrnclY3u3nVk0HrX1E1+gfPR9+SxcR1NVJ8cw+Kv3LKHNj7DoeXUVTSQplqLq0hGxtB/sBL1J8=" Jan 27 16:58:56 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:58:56 volumio sudo[24200]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 16:58:56 volumio sudo[24200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 16:58:56 volumio sudo[24200]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="completed keyexchange" Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=debug msg="completed challenge" Jan 27 16:58:56 volumio go-librespot[24174]: time="2026-01-27T16:58:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:58:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:58:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:58:57 volumio volumio[24113]: Starting albumart workers Jan 27 16:58:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:57 volumio volumio[24112]: Starting albumart workers Jan 27 16:58:57 volumio volumio[24114]: Starting albumart workers Jan 27 16:58:57 volumio volumio[23990]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:58:57 volumio volumio[23990]: info: [1769507937775] CoreMusicLibrary::Adding element YouTube Music Jan 27 16:58:57 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:58:57 volumio volumio[23990]: Cannot find translation for source YouTube Music Jan 27 16:58:57 volumio volumio[23990]: info: Volumio Calling Home Jan 27 16:58:57 volumio sudo[24219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 16:58:57 volumio sudo[24219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:58 volumio sudo[24219]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:58 volumio volumio[23990]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 16:58:58 volumio volumio[23990]: info: Discovery: Found device Volumio Jan 27 16:58:58 volumio volumio[23990]: info: CoreCommandRouter::volumioGetState Jan 27 16:58:58 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:58 volumio volumio[23990]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 16:58:58 volumio volumio[23990]: info: Discovery: Found device Volumio Jan 27 16:58:58 volumio volumio[23990]: info: CoreCommandRouter::volumioGetState Jan 27 16:58:58 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:58:59 volumio volumio[23990]: info: MPD Permissions set Jan 27 16:58:59 volumio volumio[23990]: info: MPD Permissions set Jan 27 16:58:59 volumio volumio[23990]: info: Upmpdcli Daemon Started Jan 27 16:58:59 volumio volumio[23990]: info: Volumio called home Jan 27 16:58:59 volumio volumio[23990]: info: Spotify config file written Jan 27 16:58:59 volumio sudo[24231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 16:58:59 volumio sudo[24231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:58:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:58:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:58:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:58:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:58:59 volumio go-librespot[24239]: go-librespot daemon starting... Jan 27 16:58:59 volumio sudo[24231]: pam_unix(sudo:session): session closed for user root Jan 27 16:58:59 volumio go-librespot[24240]: time="2026-01-27T16:58:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:58:59 volumio go-librespot[24240]: time="2026-01-27T16:58:59+07:00" level=debug msg="app state loaded" Jan 27 16:58:59 volumio go-librespot[24240]: time="2026-01-27T16:58:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:58:59 volumio volumio[23990]: 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 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:58:59 volumio volumio[23990]: info: No need to fix Spotify hosts Jan 27 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+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 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+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 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+07:00" level=info msg="zeroconf server listening on port 32789" Jan 27 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+07:00" level=debug msg="obtained new client token: AAAH5jsKs3U69v4YisJXeXLzAAnSKBLQVI5XhWP688eyaY4z26icuMzcrSZ5Rn+DyJJzipn1ZBVczjfpFU1CU23OFvP3nlF7aED4CE3ee/yrbU1Z4whdpvcaAcvAavSxK6ZE5OL2fVNhG91GJb5GTQuQSQPpOM+fLTZbdJcbGpuWxcl4mEcwo5fZ8dokSteARgx4pwKW0PxCDDAtgzVcDFRi0fLEU+TjY5RYdz/syfB+WS5gQ9eaVi578J0=" Jan 27 16:59:00 volumio volumio[23990]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 16:59:00 volumio volumio[23990]: SPOTIFY: BQC_0DxHpXbwfS16TcbPhaFSjSHjn4wAlrM8C6R1quzSf0LLeknp-WRzwSXRrHOTADrkmTZ9Hrqai7fQTdXowuXsrEm4vvlhZkGGkhJjqZMhfmQdC63v9aP9F1T_yFPgE3aGc79AAKWsrNF80smYQLL-AmkW0rRqUvFCrMjqSue-PHLC5LjP_eJZ8wuFnPhxLTjuVKFUG_2etf5EhbD-9QMBwXTZ4473gHZSqSVZmOcrGddqoBO-BJjSuiz5xH0QmLGbf7iX_xeijTXtyFvz4_Qufnu9S-f7dd60RPT1H5I7uNbcR2Bf7c6N Jan 27 16:59:00 volumio volumio[23990]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 16:59:00 volumio volumio[23990]: info: New Spotify access token = BQC_0DxHpXbwfS16TcbPhaFSjSHjn4wAlrM8C6R1quzSf0LLeknp-WRzwSXRrHOTADrkmTZ9Hrqai7fQTdXowuXsrEm4vvlhZkGGkhJjqZMhfmQdC63v9aP9F1T_yFPgE3aGc79AAKWsrNF80smYQLL-AmkW0rRqUvFCrMjqSue-PHLC5LjP_eJZ8wuFnPhxLTjuVKFUG_2etf5EhbD-9QMBwXTZ4473gHZSqSVZmOcrGddqoBO-BJjSuiz5xH0QmLGbf7iX_xeijTXtyFvz4_Qufnu9S-f7dd60RPT1H5I7uNbcR2Bf7c6N Jan 27 16:59:00 volumio volumio[23990]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 16:59:00 volumio volumio[23990]: info: Starting Shairport Sync Jan 27 16:59:00 volumio volumio[23990]: info: Starting Shairport Sync Jan 27 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:00 volumio volumio[23990]: info: Starting Shairport Sync Jan 27 16:59:00 volumio sudo[24264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:59:00 volumio sudo[24264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:00 volumio go-librespot[24240]: time="2026-01-27T16:59:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 16:59:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:00 volumio sudo[24268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:59:00 volumio sudo[24268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:00 volumio sudo[24266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:59:00 volumio sudo[24266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 16:59:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 16:59:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:00 volumio systemd[1]: shairport-sync.service: Consumed 2.373s CPU time. Jan 27 16:59:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:00 volumio sudo[24268]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:00 volumio sudo[24264]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:00 volumio volumio[23990]: info: Shairport-Sync Started Jan 27 16:59:00 volumio volumio[23990]: Error adding Membership: Error: addMembership EINVAL Jan 27 16:59:00 volumio volumio[23990]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:00 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:00 volumio volumio[23990]: info: Shairport-Sync Started Jan 27 16:59:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 16:59:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 16:59:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:01 volumio sudo[24266]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:01 volumio volumio[23990]: info: Shairport-Sync Started Jan 27 16:59:01 volumio volumio[23990]: 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 16:59:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:01 volumio volumio[23990]: info: Spotify Successfully logged in Jan 27 16:59:01 volumio volumio[23990]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:59:01 volumio volumio[23990]: info: [1769507941337] CoreMusicLibrary::Adding element Spotify Jan 27 16:59:01 volumio volumio[23990]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:01 volumio volumio[23990]: Cannot find translation for source YouTube Music Jan 27 16:59:01 volumio volumio[23990]: Cannot find translation for source Spotify Jan 27 16:59:01 volumio volumio[23990]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 16:59:01 volumio volumio[23990]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:59:02 volumio volumio[23990]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:59:02 volumio volumio[23990]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:02 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:02 volumio volumio[23990]: info: CoreStateMachine::pushState Jan 27 16:59:02 volumio volumio[23990]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:02 volumio volumio[23990]: info: CoreCommandRouter::volumioPushState Jan 27 16:59:03 volumio volumio[23990]: info: go-librespot daemon successfully initialized Jan 27 16:59:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:03 volumio mpd[24216]: 2026-01-27T16:59:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 16:59:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Jan 27 16:59:03 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 16:59:03 volumio sudo[24185]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:03 volumio sudo[24168]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:03 volumio go-librespot[24307]: go-librespot daemon starting... Jan 27 16:59:03 volumio go-librespot[24310]: time="2026-01-27T16:59:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:03 volumio go-librespot[24310]: time="2026-01-27T16:59:03+07:00" level=debug msg="app state loaded" Jan 27 16:59:03 volumio go-librespot[24310]: time="2026-01-27T16:59:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:03 volumio volumio[23990]: error: MPD error: The expression evaluated to a falsy value: Jan 27 16:59:03 volumio volumio[23990]: assert.ok(self.idling) Jan 27 16:59:03 volumio volumio[23990]: error: The expression evaluated to a falsy value: Jan 27 16:59:03 volumio volumio[23990]: assert.ok(self.idling) Jan 27 16:59:03 volumio volumio[23990]: error: updateQueue error: null Jan 27 16:59:04 volumio volumio[23990]: info: MPD running with PID24216 Jan 27 16:59:04 volumio volumio[23990]: ,establishing connection Jan 27 16:59:04 volumio volumio[23990]: info: Completed starting Core Plugins Jan 27 16:59:04 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:59:04 volumio volumio[23990]: info: ----- MyVolumio plugins startup ---- Jan 27 16:59:04 volumio volumio[23990]: info: ------------------------------------------- Jan 27 16:59:04 volumio volumio[23990]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 16:59:04 volumio volumio[23990]: error: updateQueue error: null Jan 27 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+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 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+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 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+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 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+07:00" level=info msg="zeroconf server listening on port 44011" Jan 27 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+07:00" level=debug msg="obtained new client token: AADXm2U08QP7EjlpZp0NddbFH7xYOX0dWRL3Aknt9GsPpOoLAvI+tMMRRni1v5R8jAt4jj2yQL+bARb4kJySNtw6N1QsXWsU823wWlm7PzOZ/LIUnwb/26AX79GU3ekVX2kuDqsGrOv5woYTAjThLnAd0iFY74zAEiV5C3Az+4RCZGjzlS26CzN0A20zberSdYZPBy2GGN+bI5GR5K83Ycw/BSCj71XYMZnAEim3U7ji1aDocTVbv5M5ch8=" Jan 27 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:04 volumio go-librespot[24310]: time="2026-01-27T16:59:04+07:00" level=debug msg="completed challenge" Jan 27 16:59:05 volumio go-librespot[24310]: time="2026-01-27T16:59:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:06 volumio volumio[23990]: info: Initializing connection to go-librespot Websocket Jan 27 16:59:06 volumio volumio[23990]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 16:59:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Jan 27 16:59:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:08 volumio go-librespot[24319]: go-librespot daemon starting... Jan 27 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59:08+07:00" level=debug msg="app state loaded" Jan 27 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:08 volumio volumio[23990]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59:08+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 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59:08+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 16:59:08 volumio go-librespot[24320]: time="2026-01-27T16:59:08+07:00" level=info msg="zeroconf server listening on port 39511" Jan 27 16:59:09 volumio go-librespot[24320]: time="2026-01-27T16:59:09+07:00" level=debug msg="obtained new client token: AAAGpZH2b6VA848Nj0PHo7R+RFFr4l8cw7HzH8n7GXcrxCV5qIgvM0/jO7zNF4Mu9IGPwC0/8+kbgoVoSP+UCEbqNSLUX7mVOOiOUlwovisqh4mz2fVi7DTlxltuQPD7tcd3M6QOgsLO5NljSWqmZTP1L0DdHwg3h5U1dKrjlhsW03xMc5L86zWwC0MgDK1nQfWi9mWtxw0yMxVFFpVlE9Q7ZkCleMccd/hN4UqLSPYf+pRTUjSRpXiC" Jan 27 16:59:09 volumio go-librespot[24320]: time="2026-01-27T16:59:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:09 volumio go-librespot[24320]: time="2026-01-27T16:59:09+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:09 volumio go-librespot[24320]: time="2026-01-27T16:59:09+07:00" level=debug msg="completed challenge" Jan 27 16:59:09 volumio volumio[23990]: info: Initializing connection to go-librespot Websocket Jan 27 16:59:09 volumio go-librespot[24320]: time="2026-01-27T16:59:09+07:00" level=debug msg="new websocket client" Jan 27 16:59:09 volumio volumio[23990]: info: Connection to go-librespot Websocket established Jan 27 16:59:09 volumio go-librespot[24320]: time="2026-01-27T16:59:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:09 volumio volumio[23990]: info: Connection to go-librespot Websocket closed Jan 27 16:59:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:12 volumio volumio[23990]: info: Getting Spotify volume Jan 27 16:59:12 volumio volumio[23990]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 16:59:12 volumio volumio[23990]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 16:59:12 volumio volumio[23990]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 16:59:12 volumio volumio[23990]: errno: -111, Jan 27 16:59:12 volumio volumio[23990]: code: 'ECONNREFUSED', Jan 27 16:59:12 volumio volumio[23990]: syscall: 'connect', Jan 27 16:59:12 volumio volumio[23990]: address: '127.0.0.1', Jan 27 16:59:12 volumio volumio[23990]: port: 9879, Jan 27 16:59:12 volumio volumio[23990]: response: undefined Jan 27 16:59:12 volumio volumio[23990]: } Jan 27 16:59:12 volumio volumio[23990]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 16:59:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Jan 27 16:59:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:12 volumio go-librespot[24330]: go-librespot daemon starting... Jan 27 16:59:12 volumio go-librespot[24339]: time="2026-01-27T16:59:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:12 volumio go-librespot[24339]: time="2026-01-27T16:59:12+07:00" level=debug msg="app state loaded" Jan 27 16:59:12 volumio go-librespot[24339]: time="2026-01-27T16:59:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=info msg="zeroconf server listening on port 41145" Jan 27 16:59:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="obtained new client token: AAB41rsyAcqU02XIzXAXTGdbyIjP8DfCHF1c6hnMmcsAHtdAoPCwmQfx9PNmh/glwyeAUFBixVclI2tsoQE7N58Ju7rx/lsTAYFuHvkVWCtBOGVSk/CQPkav00gK6CTPwBg2d93VjUPTH/vyeUmQRrnducFZ9W7behCHuZHOLtCJdZ+OnpNo/Ke+V+Aqeosv95T/uIA4IQ3a6cJ2qWbr+hto9nad9ewcFA5VSIoKfCKKMHp/DrtTacvjbyI=" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59:13+07:00" level=debug msg="completed challenge" Jan 27 16:59:13 volumio go-librespot[24339]: time="2026-01-27T16:59: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 16:59:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:13 volumio sudo[24363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 16:58' Jan 27 16:59:13 volumio sudo[24363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:14 volumio sudo[24363]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:14 volumio volumio-remote-updater[628]: [2026-01-27 16:59:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 16:59:14 volumio volumio-remote-updater[628]: [2026-01-27 16:59:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 16:59:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 16:59:14 volumio systemd[1]: volumio.service: Consumed 59.845s CPU time. Jan 27 16:59:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 16:59:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 16:59:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8861. Jan 27 16:59:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 16:59:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 16:59:14 volumio systemd[1]: volumio.service: Consumed 59.845s CPU time. Jan 27 16:59:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 16:59:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 16:59:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Jan 27 16:59:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:17 volumio go-librespot[24390]: go-librespot daemon starting... Jan 27 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59:17+07:00" level=debug msg="app state loaded" Jan 27 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59: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 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59: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 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59: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 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59:17+07:00" level=info msg="zeroconf server listening on port 46565" Jan 27 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59:17+07:00" level=debug msg="obtained new client token: AACeLrSEbOi1N8nKMxR1HbEPbrLtjm40u91pgzjzcGl20LlRZYF9HzUx1NRcRunKCPjRIt0gmd+yRzke1+EU8aCE380hLDk2YT04t8U1In4FpCLoPtTE2HfrwS/bPtTiUH4ypvXhTJ0370BqPHKK0C8wITfOE1pAxrd4PjSMM5nUSWkTQ08VhKYoIRd69MAUHnX676cF2SJ/ilJIMWkKyBabtJ1IqlDaAuwxvmc0N7Lt05Sgowyalsqn4FI=" Jan 27 16:59:17 volumio go-librespot[24391]: time="2026-01-27T16:59:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:18 volumio go-librespot[24391]: time="2026-01-27T16:59:18+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:18 volumio go-librespot[24391]: time="2026-01-27T16:59:18+07:00" level=debug msg="completed challenge" Jan 27 16:59:18 volumio go-librespot[24391]: time="2026-01-27T16:59:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:18 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:18 volumio volumio[24375]: info: ----- Volumio3 ---- Jan 27 16:59:18 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:18 volumio volumio[24375]: info: ----- System startup ---- Jan 27 16:59:18 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:19 volumio volumio-remote-updater[628]: [2026-01-27 16:59:19] [connect] Successful connection Jan 27 16:59:19 volumio volumio[24375]: info: MYVOLUMIO Environment detected Jan 27 16:59:19 volumio volumio[24375]: info: Plugin folders cleanup Jan 27 16:59:19 volumio volumio[24375]: info: Scanning into folder /volumio/app/plugins/ Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category audio_interface Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category miscellanea Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category music_service Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category plugins.json Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category system_controller Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category user_interface Jan 27 16:59:19 volumio volumio[24375]: info: Scanning into folder /data/plugins/ Jan 27 16:59:19 volumio volumio[24375]: info: Scanning category music_service Jan 27 16:59:19 volumio volumio[24375]: info: Plugin folders cleanup completed Jan 27 16:59:19 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:19 volumio volumio[24375]: info: ----- Core plugins startup ---- Jan 27 16:59:19 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:19 volumio volumio[24375]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 16:59:19 volumio volumio[24375]: info: Adding plugin upnp to MyMusic Plugins Jan 27 16:59:19 volumio volumio[24375]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 16:59:19 volumio volumio[24375]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 16:59:19 volumio volumio[24375]: info: Loading plugins from folder /data/plugins/ Jan 27 16:59:19 volumio volumio[24375]: info: Loading plugin "system"... Jan 27 16:59:19 volumio volumio[24375]: info: Loading plugin "appearance"... Jan 27 16:59:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Jan 27 16:59:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:21 volumio go-librespot[24410]: go-librespot daemon starting... Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=debug msg="app state loaded" Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:21 volumio volumio[24375]: info: Loading plugin "network"... Jan 27 16:59:21 volumio volumio[24375]: info: Refreshing Cached IP Addresses Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:59:21 volumio sudo[24419]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 16:59:21 volumio sudo[24419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:21 volumio go-librespot[24411]: time="2026-01-27T16:59:21+07:00" level=info msg="zeroconf server listening on port 42647" Jan 27 16:59:21 volumio sudo[24421]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 16:59:21 volumio sudo[24421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:21 volumio sudo[24419]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:21 volumio volumio[24375]: info: Loading plugin "services"... Jan 27 16:59:21 volumio sudo[24421]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:21 volumio volumio[24375]: info: Loading plugin "alsa_controller"... Jan 27 16:59:22 volumio sudo[24428]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 16:59:22 volumio sudo[24428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:22 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "wizard"... Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "networkfs"... Jan 27 16:59:22 volumio volumio[24375]: info: Starting Udev Watcher for removable devices Jan 27 16:59:22 volumio go-librespot[24411]: time="2026-01-27T16:59:22+07:00" level=debug msg="obtained new client token: AACl0o+KWry5e3J4bL1LtKLCqih5PrPkMR/YcGXvsImVamPrU4Qzdm9nGN2bnctftBiYi1UOov1zZDJam4w3PU583Fjki4T8kwFNCaa7exJdu7irXpRoNx1SZhuMkowo/OqxKLnrjCslBtXBlBsO+pBY3CPavC/f5oZodojrmlHZ20Q6fosb/+0YGRvkB8ZoEQyyomqN9xDyCuVmyDMjSwge7bvK16SAvjnEzRXadZdGiurjndVkJM2E" Jan 27 16:59:22 volumio volumio[24375]: info: Ignoring mount for partition: boot Jan 27 16:59:22 volumio volumio[24375]: info: Ignoring mount for partition: volumio Jan 27 16:59:22 volumio volumio[24375]: info: Ignoring mount for partition: volumio_data Jan 27 16:59:22 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "volumio_command_line_client"... Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "upnp"... Jan 27 16:59:22 volumio volumio[24375]: info: [1769507962304] Starting Upmpd Daemon Jan 27 16:59:22 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "my_music"... Jan 27 16:59:22 volumio go-librespot[24411]: time="2026-01-27T16:59:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "mpd"... Jan 27 16:59:22 volumio go-librespot[24411]: time="2026-01-27T16:59:22+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:22 volumio go-librespot[24411]: time="2026-01-27T16:59:22+07:00" level=debug msg="completed challenge" Jan 27 16:59:22 volumio go-librespot[24411]: time="2026-01-27T16:59: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 16:59:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:22 volumio volumio[24375]: info: Loading plugin "upnp_browser"... Jan 27 16:59:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:24 volumio sudo[24428]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Jan 27 16:59:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:25 volumio go-librespot[24452]: go-librespot daemon starting... Jan 27 16:59:25 volumio volumio[24375]: info: Starting UPNP Browser Jan 27 16:59:25 volumio volumio[24375]: info: Loading plugin "alarm-clock"... Jan 27 16:59:25 volumio go-librespot[24453]: time="2026-01-27T16:59:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:25 volumio go-librespot[24453]: time="2026-01-27T16:59:25+07:00" level=debug msg="app state loaded" Jan 27 16:59:25 volumio go-librespot[24453]: time="2026-01-27T16:59:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:26 volumio volumio[24375]: info: Loading plugin "airplay_emulation"... Jan 27 16:59:26 volumio volumio[24375]: info: Starting Shairport Sync Jan 27 16:59:26 volumio volumio[24375]: info: Loading plugin "last_100"... Jan 27 16:59:26 volumio volumio[24375]: info: Loading plugin "webradio"... Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=info msg="zeroconf server listening on port 37715" Jan 27 16:59:26 volumio volumio[24375]: info: Loading plugin "i2s_dacs"... Jan 27 16:59:26 volumio volumio[24375]: info: Loading plugin "volumiodiscovery"... Jan 27 16:59:26 volumio volumio[24375]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 16:59:26 volumio volumio[24375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:59:26 volumio volumio[24375]: *** WARNING *** For more information see Jan 27 16:59:26 volumio volumio[24375]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 16:59:26 volumio volumio[24375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:59:26 volumio volumio[24375]: *** WARNING *** For more information see Jan 27 16:59:26 volumio node[24375]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 16:59:26 volumio node[24375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:59:26 volumio node[24375]: *** WARNING *** For more information see Jan 27 16:59:26 volumio node[24375]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 16:59:26 volumio node[24375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 16:59:26 volumio node[24375]: *** WARNING *** For more information see Jan 27 16:59:26 volumio volumio[24375]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 16:59:26 volumio volumio[24375]: info: Discovery: Started advertising with name: Volumio Jan 27 16:59:26 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 16:59:26 volumio volumio[24375]: info: Loading plugin "spop"... Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="obtained new client token: AADPeK7RqhKBiHLXvxTJ1e4rdzvO7KNZeKilAYWU5NriMUOeZuyhST6zG/tmW9ByeGACUBHTDj/pPE7ZxUa9IlbUnz6wAgdZXJeb1aZffRe2kCAvSqZyDWZ2mFhMMFsQ3deXMuAg4q5CXMNCPO8CB8zOjH9qiXzLSTQGMIg1fBve6TS4stJnbFRuEISkJ6G/+tAaaTRZMtIK/y1RGZNi/Sf5888E5cjDd/SkCDniAQ2UPIhQsKeTW+Qz2B4=" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=debug msg="completed challenge" Jan 27 16:59:26 volumio go-librespot[24453]: time="2026-01-27T16:59:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:28 volumio volumio[24375]: info: Loading plugin "ytcr"... Jan 27 16:59:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Jan 27 16:59:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:30 volumio go-librespot[24463]: go-librespot daemon starting... Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=debug msg="app state loaded" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=info msg="zeroconf server listening on port 36177" Jan 27 16:59:30 volumio go-librespot[24464]: time="2026-01-27T16:59:30+07:00" level=debug msg="obtained new client token: AADuJFbpfqqp2evylxWZvJ3pXHBY1M3VPEMA6Dh2x21uxsDDEAMe5gcDmh8OcZfQfC5nw1JNQfDnvBzo+nIVcPq0iHk/L4M3OvbO1yCSTse9nyTvdlKI1rKoX/b9tVAMSzBWY+3BMK4rZPF7nYqbXFZljQk27ICZUsmKSuqm5HsenGvAx6fvfRw9z/YKHzs7JmsrtNdiLq95tCS6dDodb18VaYFImCFeCWnEm8Qkm7o/eDuAaCJb9IF2GYQ=" Jan 27 16:59:31 volumio go-librespot[24464]: time="2026-01-27T16:59:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:31 volumio go-librespot[24464]: time="2026-01-27T16:59:31+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:31 volumio go-librespot[24464]: time="2026-01-27T16:59:31+07:00" level=debug msg="completed challenge" Jan 27 16:59:31 volumio volumio[24375]: info: Loading plugin "ytmusic"... Jan 27 16:59:31 volumio go-librespot[24464]: time="2026-01-27T16:59:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:31 volumio volumio-remote-updater[628]: [2026-01-27 16:59:31] [connect] Successful connection Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "outputs"... Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "albumart"... Jan 27 16:59:32 volumio volumio[24375]: info: Plugin example_plugin is not enabled Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "inputs"... Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "updater_comm"... Jan 27 16:59:32 volumio volumio[24375]: info: Plugin mpdemulation is not enabled Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "rest_api"... Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "websocket"... Jan 27 16:59:32 volumio volumio[24375]: info: Starting Socket.io Server version 1.7.4 Jan 27 16:59:32 volumio volumio[24375]: info: Loading plugin "RoonBridge"... Jan 27 16:59:32 volumio volumio[24375]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 16:59:32 volumio volumio[24375]: info: Loading i18n strings for locale en Jan 27 16:59:33 volumio volumio[24375]: Updating browse sources language Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::initPlayerControls Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:59:33 volumio volumio[24375]: Express server listening on port 3000 Jan 27 16:59:33 volumio volumio[24375]: [Metrics] WebUI: 15s 880.31ms Jan 27 16:59:33 volumio volumio[24485]: Forking 3 albumart workers Jan 27 16:59:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:33 volumio volumio[24375]: info: CoreStateMachine::resetVolumioState Jan 27 16:59:33 volumio volumio[24375]: info: CoreStateMachine::getcurrentVolume Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:59:33 volumio sudo[24510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 16:59:33 volumio sudo[24510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:33 volumio sudo[24510]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:33 volumio sudo[24512]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 16:59:33 volumio sudo[24512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:33 volumio sudo[24512]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:33 volumio volumio[24375]: info: Volumio Network Manager: Network status updated: 1 Jan 27 16:59:33 volumio volumio[24375]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:59:33 volumio volumio[24375]: info: CoreStateMachine::pushState Jan 27 16:59:33 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::volumioPushState Jan 27 16:59:33 volumio volumio[24375]: info: CoreStateMachine::updateTrackBlock Jan 27 16:59:33 volumio volumio[24375]: info: CorePlayQueue::getTrackBlock Jan 27 16:59:33 volumio volumio[24375]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:59:33 volumio volumio-remote-updater[628]: [2026-01-27 16:59:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769507971 101 Jan 27 16:59:33 volumio volumio[24375]: 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 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:34 volumio volumio[24375]: info: Reloading queue from file Jan 27 16:59:34 volumio volumio[24375]: info: CoreStateMachine::setRepeat null single undefined Jan 27 16:59:34 volumio volumio[24375]: info: CoreStateMachine::pushState Jan 27 16:59:34 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::volumioPushState Jan 27 16:59:34 volumio volumio[24375]: info: CoreStateMachine::setRandom null Jan 27 16:59:34 volumio volumio[24375]: info: CoreStateMachine::pushState Jan 27 16:59:34 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::volumioPushState Jan 27 16:59:34 volumio volumio[24375]: info: Setting Device type: Raspberry PI Jan 27 16:59:34 volumio volumio[24375]: info: Completed loading Core Plugins Jan 27 16:59:34 volumio volumio[24375]: info: Preparing to generate the ALSA configuration file Jan 27 16:59:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Jan 27 16:59:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:34 volumio volumio[24375]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:59:34 volumio volumio[24375]: info: CoreStateMachine::pushState Jan 27 16:59:34 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::volumioPushState Jan 27 16:59:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:34 volumio go-librespot[24544]: go-librespot daemon starting... Jan 27 16:59:34 volumio volumio[24375]: info: Asound.conf file unchanged, so no further update is needed Jan 27 16:59:34 volumio volumio[24375]: info: Output device has changed, restarting MPD Jan 27 16:59:34 volumio go-librespot[24546]: time="2026-01-27T16:59:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:34 volumio go-librespot[24546]: time="2026-01-27T16:59:34+07:00" level=debug msg="app state loaded" Jan 27 16:59:34 volumio go-librespot[24546]: time="2026-01-27T16:59:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:34 volumio volumio[24375]: info: Output device has changed, restarting Shairport Sync Jan 27 16:59:34 volumio sudo[24553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 16:59:34 volumio sudo[24553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:34 volumio sudo[24555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 16:59:34 volumio sudo[24555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:34 volumio sudo[24555]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:34 volumio sudo[24553]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:34 volumio sudo[24557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 16:59:34 volumio sudo[24557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:34 volumio volumio[24375]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:59:34 volumio volumio[24375]: info: ___________ START PLUGINS ___________ Jan 27 16:59:34 volumio volumio[24375]: info: ControllerMpd::onStart: Initializing MPD Jan 27 16:59:34 volumio volumio[24375]: info: Creating MPD Configuration file Jan 27 16:59:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:59:34 volumio volumio[24375]: info: [1769507974831] CoreMusicLibrary::Adding element Media Servers Jan 27 16:59:34 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:34 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 16:59:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 16:59:34 volumio systemd[1]: mpd.service: Consumed 7.366s CPU time. Jan 27 16:59:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 16:59:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 16:59:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 16:59:34 volumio sudo[24566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 16:59:34 volumio sudo[24566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:34 volumio sudo[24566]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:34 volumio volumio[24375]: info: UPNP Browser: Client initialized successfully Jan 27 16:59:34 volumio sudo[24568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 16:59:34 volumio sudo[24568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 16:59:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:35 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 16:59:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 16:59:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 16:59:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 16:59:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 16:59:35 volumio volumio[24375]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=info msg="zeroconf server listening on port 38725" Jan 27 16:59:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 16:59:35 volumio volumio[24375]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:59:35 volumio volumio[24375]: info: [1769507975292] CoreMusicLibrary::Adding element Last_100 Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:59:35 volumio volumio[24375]: info: [1769507975304] CoreMusicLibrary::Adding element Webradio Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:59:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:35 volumio volumio[24375]: info: Initializing BBC Radios Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="obtained new client token: AABEANMd417UYJsFvOSpdAIfWoSRNarw0khoMdkokYfPO7x8M9+iTtJlj3lDGP4MB5W0fY7xY/2O9Dr5yasIuKWpxgvtCA1VgAtkDZjQksvUGiflodDR8bHcMt3Wy4ccILkHydXbLJNDYEmkch0vHZSm43QgOQzE7wEIX3ScZH7A1KmcPoy+Ai1JNTLCllYUr2tgo13ZPm1MYTSpNG7rLfx9oVaO+6+P0Zu88XqMq+j0x+78bWQUAhGRggA=" Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:35 volumio volumio[24375]: info: Creating Spotify config file Jan 27 16:59:35 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=debug msg="completed challenge" Jan 27 16:59:35 volumio sudo[24583]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 16:59:35 volumio sudo[24583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 16:59:35 volumio sudo[24583]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:35 volumio go-librespot[24546]: time="2026-01-27T16:59:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:36 volumio volumio[24375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:59:36 volumio volumio[24375]: info: [1769507976639] CoreMusicLibrary::Adding element YouTube Music Jan 27 16:59:36 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:36 volumio volumio[24375]: Cannot find translation for source YouTube Music Jan 27 16:59:36 volumio volumio[24499]: Starting albumart workers Jan 27 16:59:36 volumio volumio[24375]: info: Volumio Calling Home Jan 27 16:59:36 volumio sudo[24600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 16:59:36 volumio sudo[24600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:36 volumio sudo[24600]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:37 volumio volumio[24501]: Starting albumart workers Jan 27 16:59:37 volumio volumio[24498]: Starting albumart workers Jan 27 16:59:37 volumio volumio[24375]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 16:59:37 volumio volumio[24375]: info: Discovery: Found device Volumio Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:37 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:37 volumio volumio[24375]: info: MPD Permissions set Jan 27 16:59:37 volumio volumio[24375]: info: MPD Permissions set Jan 27 16:59:37 volumio volumio[24375]: info: Upmpdcli Daemon Started Jan 27 16:59:37 volumio volumio[24375]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 16:59:37 volumio volumio[24375]: info: Discovery: Found device Volumio Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:37 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:37 volumio volumio[24375]: info: Volumio called home Jan 27 16:59:37 volumio volumio[24375]: info: Spotify config file written Jan 27 16:59:37 volumio sudo[24607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 16:59:37 volumio sudo[24607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:37 volumio volumio[24375]: 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 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:37 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 16:59:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:37 volumio go-librespot[24614]: go-librespot daemon starting... Jan 27 16:59:37 volumio volumio[24375]: info: No need to fix Spotify hosts Jan 27 16:59:37 volumio sudo[24607]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:37 volumio go-librespot[24620]: time="2026-01-27T16:59:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:37 volumio go-librespot[24620]: time="2026-01-27T16:59:37+07:00" level=debug msg="app state loaded" Jan 27 16:59:37 volumio go-librespot[24620]: time="2026-01-27T16:59:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:38 volumio go-librespot[24620]: time="2026-01-27T16:59:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:38 volumio go-librespot[24620]: time="2026-01-27T16:59:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:59:38 volumio go-librespot[24620]: time="2026-01-27T16:59:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:59:38 volumio go-librespot[24620]: time="2026-01-27T16:59:38+07:00" level=info msg="zeroconf server listening on port 45323" Jan 27 16:59:38 volumio go-librespot[24620]: time="2026-01-27T16:59:38+07:00" level=debug msg="obtained new client token: AACvRd11CnLYq6d9ic2gUMa1RgqFL72nwv47IxJRKiIkZThjJUy8i+OoRpraroRc42ynjVHVDXBRHviY6TuCI8Gy8IpXlUl3FPHBEWutdXf3XvBeylKxyUQ1TUzE5EaW1/4+bxxhoSPMet7yQsxFIV1QIiYLjzKtTh7FZ+2sxufUTGBwIWWNDEFnzA453mj7TElwlgQZqrCZdj9dPxiGP3mAnI5kF6L4+A8pUwW47fUvobYieEURMP+V/LE=" Jan 27 16:59:39 volumio go-librespot[24620]: time="2026-01-27T16:59:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:39 volumio go-librespot[24620]: time="2026-01-27T16:59:39+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:39 volumio go-librespot[24620]: time="2026-01-27T16:59:39+07:00" level=debug msg="completed challenge" Jan 27 16:59:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:39 volumio go-librespot[24620]: time="2026-01-27T16:59:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:39 volumio volumio[24375]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 16:59:39 volumio volumio[24375]: SPOTIFY: BQBKNsDzTPaTLdFNUKxB_lpThDfdQZxzUoZRGeQWtD4smCPFfYCtAQNrolMKg47CtAG3KVYB0X48cg99AFrERLIVlKCdmY2brDUOnhZT2MHm2Y7in9w2kInfhAUHYn3SyYLC1NaCTHpr5TSLmfIP6vYz9kBxi_bPR4-5hLaPR2b43BZFDoZt5DftNB78YZzrgs7e6EXDAkwWNbgnUv-z-c_Jo8jvRJVxP6ylgqFmTYLdFYoGeKGqcooKOIgBx-dhHV-iUJKdJ32Tt7uBMCL9Nod25K5gNgji6Po1c9kXCw-hiqe1Vno0aOaG Jan 27 16:59:39 volumio volumio[24375]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 16:59:39 volumio volumio[24375]: info: New Spotify access token = BQBKNsDzTPaTLdFNUKxB_lpThDfdQZxzUoZRGeQWtD4smCPFfYCtAQNrolMKg47CtAG3KVYB0X48cg99AFrERLIVlKCdmY2brDUOnhZT2MHm2Y7in9w2kInfhAUHYn3SyYLC1NaCTHpr5TSLmfIP6vYz9kBxi_bPR4-5hLaPR2b43BZFDoZt5DftNB78YZzrgs7e6EXDAkwWNbgnUv-z-c_Jo8jvRJVxP6ylgqFmTYLdFYoGeKGqcooKOIgBx-dhHV-iUJKdJ32Tt7uBMCL9Nod25K5gNgji6Po1c9kXCw-hiqe1Vno0aOaG Jan 27 16:59:39 volumio volumio[24375]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 16:59:39 volumio volumio[24375]: info: Starting Shairport Sync Jan 27 16:59:39 volumio volumio[24375]: info: Starting Shairport Sync Jan 27 16:59:39 volumio volumio[24375]: info: Starting Shairport Sync Jan 27 16:59:39 volumio sudo[24647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:59:39 volumio sudo[24647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:39 volumio sudo[24649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:59:39 volumio sudo[24649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:39 volumio sudo[24652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 16:59:39 volumio sudo[24652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 16:59:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 16:59:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:39 volumio systemd[1]: shairport-sync.service: Consumed 2.286s CPU time. Jan 27 16:59:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:39 volumio sudo[24647]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 16:59:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 16:59:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 16:59:40 volumio sudo[24652]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:40 volumio sudo[24649]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:40 volumio volumio[24375]: info: Shairport-Sync Started Jan 27 16:59:40 volumio volumio[24375]: Error adding Membership: Error: addMembership EINVAL Jan 27 16:59:40 volumio volumio[24375]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:40 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:40 volumio volumio[24375]: info: Shairport-Sync Started Jan 27 16:59:40 volumio volumio[24375]: info: Shairport-Sync Started Jan 27 16:59:40 volumio volumio[24375]: 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 16:59:40 volumio volumio[24375]: info: Spotify Successfully logged in Jan 27 16:59:40 volumio volumio[24375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 16:59:40 volumio volumio[24375]: info: [1769507980375] CoreMusicLibrary::Adding element Spotify Jan 27 16:59:40 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 16:59:40 volumio volumio[24375]: Cannot find translation for source YouTube Music Jan 27 16:59:40 volumio volumio[24375]: Cannot find translation for source Spotify Jan 27 16:59:40 volumio volumio[24375]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 16:59:40 volumio volumio[24375]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 16:59:41 volumio volumio[24375]: info: VolumeController:: Volume=100 Mute =false Jan 27 16:59:41 volumio volumio[24375]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:41 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:41 volumio volumio[24375]: info: CoreStateMachine::pushState Jan 27 16:59:41 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:41 volumio volumio[24375]: info: CoreCommandRouter::volumioPushState Jan 27 16:59:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:42 volumio volumio[24375]: info: go-librespot daemon successfully initialized Jan 27 16:59:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Jan 27 16:59:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:42 volumio go-librespot[24688]: go-librespot daemon starting... Jan 27 16:59:42 volumio go-librespot[24689]: time="2026-01-27T16:59:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:42 volumio go-librespot[24689]: time="2026-01-27T16:59:42+07:00" level=debug msg="app state loaded" Jan 27 16:59:42 volumio go-librespot[24689]: time="2026-01-27T16:59:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:43 volumio mpd[24598]: 2026-01-27T16:59:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 16:59:43 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 16:59:43 volumio sudo[24568]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:43 volumio sudo[24557]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+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 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+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 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=info msg="zeroconf server listening on port 35425" Jan 27 16:59:43 volumio volumio[24375]: error: MPD error: The expression evaluated to a falsy value: Jan 27 16:59:43 volumio volumio[24375]: assert.ok(self.idling) Jan 27 16:59:43 volumio volumio[24375]: error: The expression evaluated to a falsy value: Jan 27 16:59:43 volumio volumio[24375]: assert.ok(self.idling) Jan 27 16:59:43 volumio volumio[24375]: error: updateQueue error: null Jan 27 16:59:43 volumio volumio[24375]: info: MPD running with PID24598 Jan 27 16:59:43 volumio volumio[24375]: ,establishing connection Jan 27 16:59:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:43 volumio volumio[24375]: info: Completed starting Core Plugins Jan 27 16:59:43 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:43 volumio volumio[24375]: info: ----- MyVolumio plugins startup ---- Jan 27 16:59:43 volumio volumio[24375]: info: ------------------------------------------- Jan 27 16:59:43 volumio volumio[24375]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 16:59:43 volumio volumio[24375]: error: updateQueue error: null Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=debug msg="obtained new client token: AAChse4WNlt7DeLK3R+HNXYZ9mksJyXr7ESLSgwZN+6nglfwF+R7mYC2CXioKXX734xCaQSty9RTYhgvyfczWCE8pcBs+lc0dzKP41z6q/KYPcwWQ3w1zxG+HauKosW4g5j9EMPm9z8m5ZlF7aeCZubm43Ml6QlxD60KQG0Y6pDb1wh6+9irfT9wLSWE8zXXdWkMGdBBF6ppFZeJUi3oAgQ2k4spYY+mwTqRJUMOxRT9Wu+CLzAgO8ZiBV0=" Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=debug msg="completed challenge" Jan 27 16:59:43 volumio go-librespot[24689]: time="2026-01-27T16:59:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:45 volumio volumio[24375]: info: Initializing connection to go-librespot Websocket Jan 27 16:59:45 volumio volumio[24375]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 16:59:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Jan 27 16:59:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:47 volumio go-librespot[24701]: go-librespot daemon starting... Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=debug msg="app state loaded" Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=info msg="zeroconf server listening on port 39601" Jan 27 16:59:47 volumio go-librespot[24702]: time="2026-01-27T16:59:47+07:00" level=debug msg="obtained new client token: AACC5I7bIcRiTx7SVAZkwoAoVnvknmesZPw6Y1+o6t3rBNSHFKFzWTvvtjwJ6IgzfIrc833aNiYvcTu9brY93nKxrLDN/zNIoQ4kGilnFxP+jBEvNajQUebvQGAjr9oNsrqxo9xOBYAtmXUH1NXv8BEO2/v2pZHk6USTRyXeQ7TrYerqMEVjpucHvtQbcMzcl3e2gd00JGDCf+8ETZyfiNWof4h0ZXZKe0Eke0sCUC7iScByyHb83a186kU=" Jan 27 16:59:48 volumio go-librespot[24702]: time="2026-01-27T16:59:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:48 volumio go-librespot[24702]: time="2026-01-27T16:59:48+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:48 volumio go-librespot[24702]: time="2026-01-27T16:59:48+07:00" level=debug msg="completed challenge" Jan 27 16:59:48 volumio volumio[24375]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 16:59:48 volumio go-librespot[24702]: time="2026-01-27T16:59:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:48 volumio volumio[24375]: info: Initializing connection to go-librespot Websocket Jan 27 16:59:48 volumio volumio[24375]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 16:59:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Jan 27 16:59:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:51 volumio go-librespot[24709]: go-librespot daemon starting... Jan 27 16:59:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+07:00" level=debug msg="app state loaded" Jan 27 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:51 volumio volumio[24375]: info: Initializing connection to go-librespot Websocket Jan 27 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+07:00" level=debug msg="new websocket client" Jan 27 16:59:51 volumio volumio[24375]: info: Connection to go-librespot Websocket established Jan 27 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+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 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+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 16:59:51 volumio go-librespot[24710]: time="2026-01-27T16:59:51+07:00" level=info msg="zeroconf server listening on port 43025" Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 16:59:52 volumio volumio[24375]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 16:59:52 volumio go-librespot[24710]: time="2026-01-27T16:59:52+07:00" level=debug msg="obtained new client token: AACn/hf0KkwNvhGmQ9Z/gYr++QOyG/G1cz38oy7e02wE0Hnbn/5B1tzO7TpXDwbBxR8hguLEwTHurFU1wKQOBheXUsevbrfqy5XmKEEuJYFR8p2PN5+XYJ/eYivDsACXkzD9/OF0nt8yZDnAbjBWd8Sp/uCW32EQiOzf+aR4mu/gfBxCjWnijbL+JAYkJ2ewYmgqznyeI9K+ycLNdEicy4r80YzvTunVIx5rv487cG24IqcmbIkbRcuU" Jan 27 16:59:52 volumio go-librespot[24710]: time="2026-01-27T16:59:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:52 volumio go-librespot[24710]: time="2026-01-27T16:59:52+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:52 volumio go-librespot[24710]: time="2026-01-27T16:59:52+07:00" level=debug msg="completed challenge" Jan 27 16:59:52 volumio go-librespot[24710]: time="2026-01-27T16:59:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:54 volumio volumio[24375]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 16:59:54 volumio volumio[24375]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 16:59:54 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:54 volumio volumio[24375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 16:59:54 volumio volumio[24375]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 16:59:54 volumio volumio[24375]: info: MyVolumio login type: Token Jan 27 16:59:54 volumio volumio[24375]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 16:59:54 volumio volumio[24375]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 16:59:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:55 volumio volumio[24375]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 16:59:55 volumio volumio[24375]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 16:59:55 volumio volumio[24375]: info: Streaming services startup Jan 27 16:59:55 volumio volumio[24375]: info: Starting Streaming Daemon Jan 27 16:59:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Jan 27 16:59:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:55 volumio sudo[24733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 16:59:55 volumio sudo[24733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 16:59:55 volumio volumio[24375]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 16:59:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 16:59:55 volumio go-librespot[24732]: go-librespot daemon starting... Jan 27 16:59:55 volumio go-librespot[24739]: time="2026-01-27T16:59:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 16:59:55 volumio sudo[24733]: pam_unix(sudo:session): session closed for user root Jan 27 16:59:55 volumio go-librespot[24739]: time="2026-01-27T16:59:55+07:00" level=debug msg="app state loaded" Jan 27 16:59:55 volumio go-librespot[24739]: time="2026-01-27T16:59:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 16:59:55 volumio volumio[24375]: info: Getting Spotify volume Jan 27 16:59:56 volumio volumio[24375]: info: Connection to go-librespot Websocket closed Jan 27 16:59:56 volumio volumio[24375]: error: Cannot start Volumio Streaming Daemon Jan 27 16:59:56 volumio volumio[24375]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 16:59:56 volumio volumio[24375]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 16:59:56 volumio volumio[24375]: 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 16:59:56 volumio go-librespot[24739]: time="2026-01-27T16:59:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 16:59:56 volumio go-librespot[24739]: time="2026-01-27T16:59:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 16:59:56 volumio go-librespot[24739]: time="2026-01-27T16:59:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 16:59:56 volumio go-librespot[24739]: time="2026-01-27T16:59:56+07:00" level=info msg="zeroconf server listening on port 44585" Jan 27 16:59:56 volumio volumio[24375]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:56 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:56 volumio volumio[24375]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 16:59:56 volumio volumio[24375]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 16:59:56 volumio volumio[24375]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 16:59:56 volumio volumio[24375]: info: Aligning Spotify Volume to Volumio Volume Jan 27 16:59:56 volumio volumio[24375]: info: CoreCommandRouter::volumioGetState Jan 27 16:59:56 volumio volumio[24375]: info: CorePlayQueue::getTrack 0 Jan 27 16:59:56 volumio volumio[24375]: info: Setting Spotify Volume from Volumio: 100 Jan 27 16:59:56 volumio go-librespot[24739]: time="2026-01-27T16:59:56+07:00" level=debug msg="obtained new client token: AAA9xu3v0SbEcVLbgS1C0fTGXFbkVmX9jafNIRV/gIDnCCHjhXOwkHaSDR4VOD0fDO1RenNt0BCZXuhPgb+a4fycogOD1y6SoII3D6NWpULrEtsMcq4IM7NJEfEiS9RC/fsLsAwt3K5H1KVUYYiMyD+lJPYVj29DgESk5eS+03Zip9wFYYfQxrUPhIFF9vmRXP8AVbHq0X5pne+SrNUdw5a6S49ZEjgGb1DsCosaanNGtnlq1PCabAMyMIA=" Jan 27 16:59:56 volumio go-librespot[24739]: time="2026-01-27T16:59:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 16:59:57 volumio go-librespot[24739]: time="2026-01-27T16:59:57+07:00" level=debug msg="completed keyexchange" Jan 27 16:59:57 volumio go-librespot[24739]: time="2026-01-27T16:59:57+07:00" level=debug msg="completed challenge" Jan 27 16:59:57 volumio go-librespot[24739]: time="2026-01-27T16:59:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 16:59:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 16:59:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 16:59:57 volumio volumio[24375]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 16:59:57 volumio volumio[24375]: Error: socket hang up Jan 27 16:59:57 volumio volumio[24375]: at connResetException (node:internal/errors:720:14) Jan 27 16:59:57 volumio volumio[24375]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 16:59:57 volumio volumio[24375]: at Socket.emit (node:events:526:35) Jan 27 16:59:57 volumio volumio[24375]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 16:59:57 volumio volumio[24375]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 16:59:57 volumio volumio[24375]: code: 'ECONNRESET', Jan 27 16:59:57 volumio volumio[24375]: response: undefined Jan 27 16:59:57 volumio volumio[24375]: } Jan 27 16:59:57 volumio volumio[24375]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 16:59:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 16:59:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 16:59:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 16:59:58 volumio sudo[24761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 16:58' Jan 27 16:59:58 volumio sudo[24761]: 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"