Jan 25 23:08:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 25 23:08:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:01 volumio go-librespot[14828]: go-librespot daemon starting... Jan 25 23:08:01 volumio go-librespot[14829]: time="2026-01-25T23:08:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:01 volumio go-librespot[14829]: time="2026-01-25T23:08:01+07:00" level=debug msg="app state loaded" Jan 25 23:08:01 volumio go-librespot[14829]: time="2026-01-25T23:08:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=info msg="zeroconf server listening on port 36447" Jan 25 23:08:02 volumio volumio[14349]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="new websocket client" Jan 25 23:08:02 volumio volumio[14349]: info: Connection to go-librespot Websocket established Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::volumioGetBrowseSources Jan 25 23:08:02 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="obtained new client token: AAC8FwysZWG+bt/ejos8AWtwvm76I9lCQ6pw/TuDa0/Nc9ocdyN6j7yT42lh2TRS48hBFm/6BapAMD9a15q/7f+v9LJwnnRpVwnnillfUB9qCxGL9vr70v3sbclh5Wk8snf8rBMuDfzqjg+TOQoaoHg8I85z8RX/qPBEoM7vt5y0FCHNT+6/ofYU94UZBa+17OH4eAnOLmUXkJTnVRnB0yGhy7lyHLsyFTcKL5ouH91VWiz29/i7ACTiyFA=" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=debug msg="completed challenge" Jan 25 23:08:02 volumio go-librespot[14829]: time="2026-01-25T23:08:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:08:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:02 volumio volumio[14349]: info: Connection to go-librespot Websocket closed Jan 25 23:08:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:04 volumio volumio[14349]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jan 25 23:08:04 volumio volumio[14349]: info: Completed starting MyVolumio Plugin Jan 25 23:08:04 volumio volumio[14349]: [Metrics] CommandRouter: 57s 246.52ms Jan 25 23:08:04 volumio volumio[14349]: info: CoreCommandRouter::volumiosetStartupVolume Jan 25 23:08:04 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:04 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:04 volumio volumio[14349]: info: CoreCommandRouter::Close All Modals sent Jan 25 23:08:04 volumio volumio[14349]: info: CoreCommandRouter::Close All Modals sent Jan 25 23:08:05 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 25 23:08:05 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 25 23:08:05 volumio volumio[14349]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 25 23:08:05 volumio volumio[14349]: info: Getting Spotify volume Jan 25 23:08:05 volumio volumio[14349]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 23:08:05 volumio volumio[14349]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:05 volumio volumio[14349]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 23:08:05 volumio volumio[14349]: errno: -111, Jan 25 23:08:05 volumio volumio[14349]: code: 'ECONNREFUSED', Jan 25 23:08:05 volumio volumio[14349]: syscall: 'connect', Jan 25 23:08:05 volumio volumio[14349]: address: '127.0.0.1', Jan 25 23:08:05 volumio volumio[14349]: port: 9879, Jan 25 23:08:05 volumio volumio[14349]: response: undefined Jan 25 23:08:05 volumio volumio[14349]: } Jan 25 23:08:05 volumio volumio[14349]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 23:08:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 25 23:08:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:06 volumio go-librespot[14850]: go-librespot daemon starting... Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=debug msg="app state loaded" Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+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 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+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 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=info msg="zeroconf server listening on port 39845" Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=debug msg="obtained new client token: AADaTON2z/lnZYjwZXHTjwDceqtmoBjZYEDZiYJ+YXIZAXyVY2Ow2ftpk2OvU2WectgAT4aARJZrJ+Lvna9CZADVleYzzFDl12fuHiSNEuuRYD/ITUxNo798dWOPD8o2Mq+u/ZneOVMeMUgZiCOurLYuJJpzDa9YN4h2ECz+MmPSPHQ0JOmI6ePWxtjsB1mNCQ7GvYBvSm1nzQb8bY9jhiYcMuVzeqARUmzYzHiuWeT8y7EBrbLqnHiifsY=" Jan 25 23:08:06 volumio go-librespot[14851]: time="2026-01-25T23:08:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:07 volumio go-librespot[14851]: time="2026-01-25T23:08:07+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 25 23:08:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:07 volumio sudo[14860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 23:07' Jan 25 23:08:07 volumio sudo[14860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:07 volumio sudo[14860]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:07 volumio volumio-remote-updater[628]: [2026-01-25 23:08:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 23:08:07 volumio volumio-remote-updater[628]: [2026-01-25 23:08:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 23:08:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 23:08:07 volumio systemd[1]: volumio.service: Consumed 1min 6.075s CPU time. Jan 25 23:08:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 23:08:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 23:08:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6133. Jan 25 23:08:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 23:08:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 23:08:07 volumio systemd[1]: volumio.service: Consumed 1min 6.075s CPU time. Jan 25 23:08:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 23:08:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 23:08:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 25 23:08:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:10 volumio go-librespot[14893]: go-librespot daemon starting... Jan 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+07:00" level=debug msg="app state loaded" Jan 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+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 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+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 25 23:08:10 volumio go-librespot[14894]: time="2026-01-25T23:08:10+07:00" level=info msg="zeroconf server listening on port 42485" Jan 25 23:08:11 volumio go-librespot[14894]: time="2026-01-25T23:08:11+07:00" level=debug msg="obtained new client token: AADfJX26SnTcwiLZ7ONBar5sc6RX89NdnLNFpGRcec1589E4LGXm43a+EgVNAxntF1IWAUKclW3IR7kBcrgqnKjPucylD6cfSCygSfwE/3+c1TZCl9fk83US1TR/XdH3w5zgbZreRpFuNnNtzm3zCI72kN+kH/Lcs1NAs49oyeuWQIh65d43I2oyIMTFyRFfdygJ5DNjW96/6CXAzBN3AAca4R0UtvFIV72TJRCZmzwic4lk95NdtqOs" Jan 25 23:08:11 volumio go-librespot[14894]: time="2026-01-25T23:08:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:11 volumio go-librespot[14894]: time="2026-01-25T23:08:11+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:11 volumio go-librespot[14894]: time="2026-01-25T23:08:11+07:00" level=debug msg="completed challenge" Jan 25 23:08:11 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:11 volumio volumio[14878]: info: ----- Volumio3 ---- Jan 25 23:08:11 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:11 volumio volumio[14878]: info: ----- System startup ---- Jan 25 23:08:11 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:11 volumio go-librespot[14894]: time="2026-01-25T23:08:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:08:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:12 volumio volumio-remote-updater[628]: [2026-01-25 23:08:12] [connect] Successful connection Jan 25 23:08:12 volumio volumio[14878]: info: MYVOLUMIO Environment detected Jan 25 23:08:12 volumio volumio[14878]: info: Plugin folders cleanup Jan 25 23:08:12 volumio volumio[14878]: info: Scanning into folder /volumio/app/plugins/ Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category audio_interface Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category miscellanea Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category music_service Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category plugins.json Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category system_controller Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category user_interface Jan 25 23:08:12 volumio volumio[14878]: info: Scanning into folder /data/plugins/ Jan 25 23:08:12 volumio volumio[14878]: info: Scanning category music_service Jan 25 23:08:12 volumio volumio[14878]: info: Plugin folders cleanup completed Jan 25 23:08:12 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:12 volumio volumio[14878]: info: ----- Core plugins startup ---- Jan 25 23:08:12 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:12 volumio volumio[14878]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 23:08:12 volumio volumio[14878]: info: Adding plugin upnp to MyMusic Plugins Jan 25 23:08:12 volumio volumio[14878]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 23:08:12 volumio volumio[14878]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 23:08:12 volumio volumio[14878]: info: Loading plugins from folder /data/plugins/ Jan 25 23:08:12 volumio volumio[14878]: info: Loading plugin "system"... Jan 25 23:08:12 volumio volumio[14878]: info: Loading plugin "appearance"... Jan 25 23:08:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 25 23:08:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:14 volumio go-librespot[14914]: go-librespot daemon starting... Jan 25 23:08:14 volumio go-librespot[14915]: time="2026-01-25T23:08:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:14 volumio go-librespot[14915]: time="2026-01-25T23:08:14+07:00" level=debug msg="app state loaded" Jan 25 23:08:14 volumio go-librespot[14915]: time="2026-01-25T23:08:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:14 volumio volumio[14878]: info: Loading plugin "network"... Jan 25 23:08:14 volumio volumio[14878]: info: Refreshing Cached IP Addresses Jan 25 23:08:14 volumio sudo[14923]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 23:08:14 volumio sudo[14923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:14 volumio sudo[14923]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:14 volumio sudo[14925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 23:08:14 volumio sudo[14925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:14 volumio volumio[14878]: info: Loading plugin "services"... Jan 25 23:08:14 volumio sudo[14925]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:14 volumio volumio[14878]: info: Loading plugin "alsa_controller"... Jan 25 23:08:14 volumio sudo[14933]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 23:08:14 volumio sudo[14933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:15 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "wizard"... Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "networkfs"... Jan 25 23:08:15 volumio volumio[14878]: info: Starting Udev Watcher for removable devices Jan 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+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 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+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 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+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 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+07:00" level=info msg="zeroconf server listening on port 40433" Jan 25 23:08:15 volumio volumio[14878]: info: Ignoring mount for partition: boot Jan 25 23:08:15 volumio volumio[14878]: info: Ignoring mount for partition: volumio Jan 25 23:08:15 volumio volumio[14878]: info: Ignoring mount for partition: volumio_data Jan 25 23:08:15 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "volumio_command_line_client"... Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "upnp"... Jan 25 23:08:15 volumio volumio[14878]: info: [1769357295268] Starting Upmpd Daemon Jan 25 23:08:15 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "my_music"... Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "mpd"... Jan 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+07:00" level=debug msg="obtained new client token: AACzm/QUjli/ij3Ji4vMhBYbf4yvLBhPBetIyUdFYtwt/amdiYqrwgSW6JVkyvtY898henZ6N0QrUTfG6mlwlD0JY8BN6Vm3CIoPJnD20+JGzbb5uK4qaoq4FceJg0wwpY1oq3zqUe/xI7FRtP3YSdgNtOqbqiouxgaxRD6xk4ZikHn7Eu9zpX1HZA7ET37pDFlUUx8PhSYFKg2nOCFSNhQwQS5+mFvDyyyElWJno6jEAJx/fIcc0K0AUpE=" Jan 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:15 volumio go-librespot[14915]: time="2026-01-25T23:08:15+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 25 23:08:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:15 volumio volumio[14878]: info: Loading plugin "upnp_browser"... Jan 25 23:08:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:17 volumio sudo[14933]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 25 23:08:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:18 volumio go-librespot[14958]: go-librespot daemon starting... Jan 25 23:08:18 volumio volumio[14878]: info: Starting UPNP Browser Jan 25 23:08:18 volumio volumio[14878]: info: Loading plugin "alarm-clock"... Jan 25 23:08:18 volumio go-librespot[14959]: time="2026-01-25T23:08:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:18 volumio go-librespot[14959]: time="2026-01-25T23:08:18+07:00" level=debug msg="app state loaded" Jan 25 23:08:18 volumio go-librespot[14959]: time="2026-01-25T23:08:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:19 volumio volumio[14878]: info: Loading plugin "airplay_emulation"... Jan 25 23:08:19 volumio volumio[14878]: info: Starting Shairport Sync Jan 25 23:08:19 volumio volumio[14878]: info: Loading plugin "last_100"... Jan 25 23:08:19 volumio volumio[14878]: info: Loading plugin "webradio"... Jan 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+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 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+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 25 23:08:19 volumio volumio[14878]: info: Loading plugin "i2s_dacs"... Jan 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+07:00" level=info msg="zeroconf server listening on port 35409" Jan 25 23:08:19 volumio volumio[14878]: info: Loading plugin "volumiodiscovery"... Jan 25 23:08:19 volumio volumio[14878]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 23:08:19 volumio volumio[14878]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:08:19 volumio volumio[14878]: *** WARNING *** For more information see Jan 25 23:08:19 volumio volumio[14878]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 23:08:19 volumio volumio[14878]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:08:19 volumio volumio[14878]: *** WARNING *** For more information see Jan 25 23:08:19 volumio node[14878]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 23:08:19 volumio node[14878]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:08:19 volumio node[14878]: *** WARNING *** For more information see Jan 25 23:08:19 volumio node[14878]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 23:08:19 volumio node[14878]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:08:19 volumio node[14878]: *** WARNING *** For more information see Jan 25 23:08:19 volumio volumio[14878]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 23:08:19 volumio volumio[14878]: info: Discovery: Started advertising with name: Volumio Jan 25 23:08:19 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 23:08:19 volumio volumio[14878]: info: Loading plugin "spop"... Jan 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+07:00" level=debug msg="obtained new client token: AADyzk5rNUeFIRCs2WVjXD03wkKqU+fsnauoFTfTjFy2mPtTVky70DeRL5eNhEkddizTJv+SIkAcEN4t1WM7JqmgxF8rf3nujT/5Z+K+Th0tm4NVlDsyFpg8humI6Trv+96PzRMa4CODRCCiL+OEmH7sVmiPRUIhfASBhk+TStMoA4hR3IcO+u0A/KDeXnuYkcl4/ZmJxeDwA1VRdPvML1viY7uzXXk+vsviX9lJLnvLwV5Ih/L3YQew7Jk=" Jan 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:19 volumio go-librespot[14959]: time="2026-01-25T23:08:19+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 25 23:08:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:21 volumio volumio[14878]: info: Loading plugin "ytcr"... Jan 25 23:08:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 25 23:08:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:23 volumio go-librespot[14970]: go-librespot daemon starting... Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=debug msg="app state loaded" Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=info msg="zeroconf server listening on port 46667" Jan 25 23:08:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:23 volumio go-librespot[14971]: time="2026-01-25T23:08:23+07:00" level=debug msg="obtained new client token: AAAZntApCOuYZ5AiF3cMlKx7yV4OtjjTOAA/Zu++y0rgNCuuyv5l6O3cY9six+TghD8+wrTeGI5rnWH+ow4fFM9DU7P6Ba3UU5kTqpu1NXq3ieTGyWEb57avXNa2RB2OuyY417frL5qNczBrN6NMODVf4qTfePWg9//RU5SHC3mB1gYobF97mKrPNojcg2UajNtoPKOSS75CTqBJo/QsQC5C+AldIG7pOh1UDTYKimLw2jMAvib5LuHTBqY=" Jan 25 23:08:24 volumio go-librespot[14971]: time="2026-01-25T23:08:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:24 volumio volumio[14878]: info: Loading plugin "ytmusic"... Jan 25 23:08:24 volumio go-librespot[14971]: time="2026-01-25T23:08:24+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:24 volumio go-librespot[14971]: time="2026-01-25T23:08:24+07:00" level=debug msg="completed challenge" Jan 25 23:08:24 volumio go-librespot[14971]: time="2026-01-25T23:08:24+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 25 23:08:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:25 volumio volumio-remote-updater[628]: [2026-01-25 23:08:25] [connect] Successful connection Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "outputs"... Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "albumart"... Jan 25 23:08:25 volumio volumio[14878]: info: Plugin example_plugin is not enabled Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "inputs"... Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "updater_comm"... Jan 25 23:08:25 volumio volumio[14878]: info: Plugin mpdemulation is not enabled Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "rest_api"... Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "websocket"... Jan 25 23:08:25 volumio volumio[14878]: info: Starting Socket.io Server version 1.7.4 Jan 25 23:08:25 volumio volumio[14878]: info: Loading plugin "RoonBridge"... Jan 25 23:08:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:25 volumio volumio[14878]: info: Applying required configuration parameters for plugin RoonBridge Jan 25 23:08:26 volumio volumio[14878]: info: Loading i18n strings for locale en Jan 25 23:08:26 volumio volumio[14878]: Updating browse sources language Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:08:26 volumio volumio[14993]: Forking 3 albumart workers Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::initPlayerControls Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 23:08:26 volumio volumio[14878]: Express server listening on port 3000 Jan 25 23:08:26 volumio volumio[14878]: [Metrics] WebUI: 15s 993.61ms Jan 25 23:08:26 volumio volumio[14878]: info: CoreStateMachine::resetVolumioState Jan 25 23:08:26 volumio volumio[14878]: info: CoreStateMachine::getcurrentVolume Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 23:08:26 volumio volumio[14878]: info: Volumio Network Manager: Network status updated: 1 Jan 25 23:08:26 volumio sudo[15035]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 23:08:26 volumio sudo[15035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:26 volumio sudo[15035]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:26 volumio sudo[15038]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 23:08:26 volumio sudo[15038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:26 volumio sudo[15038]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:26 volumio volumio[14878]: info: VolumeController:: Volume=100 Mute =false Jan 25 23:08:26 volumio volumio[14878]: info: CoreStateMachine::pushState Jan 25 23:08:26 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::volumioPushState Jan 25 23:08:26 volumio volumio[14878]: info: CoreStateMachine::updateTrackBlock Jan 25 23:08:26 volumio volumio[14878]: info: CorePlayQueue::getTrackBlock Jan 25 23:08:26 volumio volumio[14878]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 23:08:26 volumio volumio-remote-updater[628]: [2026-01-25 23:08:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769357305 101 Jan 25 23:08:27 volumio volumio[14878]: 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 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:27 volumio volumio[14878]: info: Reloading queue from file Jan 25 23:08:27 volumio volumio[14878]: info: CoreStateMachine::setRepeat null single undefined Jan 25 23:08:27 volumio volumio[14878]: info: CoreStateMachine::pushState Jan 25 23:08:27 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::volumioPushState Jan 25 23:08:27 volumio volumio[14878]: info: CoreStateMachine::setRandom null Jan 25 23:08:27 volumio volumio[14878]: info: CoreStateMachine::pushState Jan 25 23:08:27 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::volumioPushState Jan 25 23:08:27 volumio volumio[14878]: info: Setting Device type: Raspberry PI Jan 25 23:08:27 volumio volumio[14878]: info: Completed loading Core Plugins Jan 25 23:08:27 volumio volumio[14878]: info: Preparing to generate the ALSA configuration file Jan 25 23:08:27 volumio volumio[14878]: info: VolumeController:: Volume=100 Mute =false Jan 25 23:08:27 volumio volumio[14878]: info: CoreStateMachine::pushState Jan 25 23:08:27 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::volumioPushState Jan 25 23:08:27 volumio volumio[14878]: info: Asound.conf file unchanged, so no further update is needed Jan 25 23:08:27 volumio volumio[14878]: info: Output device has changed, restarting MPD Jan 25 23:08:27 volumio sudo[15054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 23:08:27 volumio volumio[14878]: info: Output device has changed, restarting Shairport Sync Jan 25 23:08:27 volumio sudo[15054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 25 23:08:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:27 volumio sudo[15056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 23:08:27 volumio sudo[15056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:27 volumio sudo[15056]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:27 volumio volumio[14878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 23:08:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:27 volumio volumio[14878]: info: ___________ START PLUGINS ___________ Jan 25 23:08:27 volumio go-librespot[15059]: go-librespot daemon starting... Jan 25 23:08:27 volumio sudo[15060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 23:08:27 volumio sudo[15060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:27 volumio sudo[15054]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:27 volumio volumio[14878]: info: ControllerMpd::onStart: Initializing MPD Jan 25 23:08:27 volumio volumio[14878]: info: Creating MPD Configuration file Jan 25 23:08:27 volumio go-librespot[15066]: time="2026-01-25T23:08:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:27 volumio go-librespot[15066]: time="2026-01-25T23:08:27+07:00" level=debug msg="app state loaded" Jan 25 23:08:27 volumio go-librespot[15066]: time="2026-01-25T23:08:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:08:27 volumio volumio[14878]: info: [1769357307750] CoreMusicLibrary::Adding element Media Servers Jan 25 23:08:27 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:08:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 23:08:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:27 volumio sudo[15075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 23:08:27 volumio sudo[15075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 23:08:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 23:08:27 volumio systemd[1]: mpd.service: Consumed 7.361s CPU time. Jan 25 23:08:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 23:08:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 23:08:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 23:08:27 volumio sudo[15075]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:27 volumio volumio[14878]: info: UPNP Browser: Client initialized successfully Jan 25 23:08:27 volumio sudo[15077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 23:08:27 volumio sudo[15077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 23:08:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 23:08:28 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 23:08:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 23:08:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 23:08:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 23:08:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 23:08:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 23:08:28 volumio volumio[14878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:28 volumio volumio[14878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:08:28 volumio volumio[14878]: info: [1769357308344] CoreMusicLibrary::Adding element Last_100 Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:08:28 volumio volumio[14878]: info: [1769357308368] CoreMusicLibrary::Adding element Webradio Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:08:28 volumio volumio[14878]: info: Initializing BBC Radios Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=info msg="zeroconf server listening on port 39251" Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:28 volumio sudo[15085]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 23:08:28 volumio sudo[15085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 23:08:28 volumio sudo[15085]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=debug msg="obtained new client token: AAA9OHAPj3XWVNEz2HHvOWOG634OfZuLE+nyq/2n5Uuk+HMdNgxLE9nX94SBUNiEdQU885KWShfUZc78PUU+kQSh5i/eh2sC4b36Bk/jFW4+UzhedcoaG0se0aHfXLM79u929wOF2RXKPEIXyUZmoa3rinltHar5QomnSMDqNENrrOz4yP87twCOwrTJuVtDCPdvpjBC03ItjLGW+AJMECFYJ7aX4UmqbZ2OrbVzeX8j5S4BlUnCqKJo2BU=" Jan 25 23:08:28 volumio volumio[14878]: info: Creating Spotify config file Jan 25 23:08:28 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+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 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 25 23:08:28 volumio go-librespot[15066]: time="2026-01-25T23:08:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 25 23:08:29 volumio go-librespot[15066]: time="2026-01-25T23:08:29+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:29 volumio go-librespot[15066]: time="2026-01-25T23:08:29+07:00" level=debug msg="completed challenge" Jan 25 23:08:29 volumio go-librespot[15066]: time="2026-01-25T23:08:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:08:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:29 volumio volumio[15005]: Starting albumart workers Jan 25 23:08:29 volumio volumio[14878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:08:29 volumio volumio[14878]: info: [1769357309764] CoreMusicLibrary::Adding element YouTube Music Jan 25 23:08:29 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:08:29 volumio volumio[14878]: Cannot find translation for source YouTube Music Jan 25 23:08:29 volumio volumio[14878]: info: Volumio Calling Home Jan 25 23:08:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:29 volumio volumio[15003]: Starting albumart workers Jan 25 23:08:29 volumio sudo[15108]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 25 23:08:29 volumio sudo[15108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:30 volumio sudo[15108]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:30 volumio volumio[15004]: Starting albumart workers Jan 25 23:08:30 volumio volumio[14878]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 23:08:30 volumio volumio[14878]: info: Discovery: Found device Volumio Jan 25 23:08:30 volumio volumio[14878]: info: CoreCommandRouter::volumioGetState Jan 25 23:08:30 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:30 volumio volumio[14878]: info: MPD Permissions set Jan 25 23:08:30 volumio volumio[14878]: info: MPD Permissions set Jan 25 23:08:30 volumio volumio[14878]: info: Upmpdcli Daemon Started Jan 25 23:08:30 volumio volumio[14878]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 23:08:30 volumio volumio[14878]: info: Discovery: Found device Volumio Jan 25 23:08:30 volumio volumio[14878]: info: CoreCommandRouter::volumioGetState Jan 25 23:08:30 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:30 volumio volumio[14878]: info: Volumio called home Jan 25 23:08:30 volumio volumio[14878]: info: Spotify config file written Jan 25 23:08:31 volumio sudo[15114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 23:08:31 volumio sudo[15114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:31 volumio volumio[14878]: 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 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:31 volumio go-librespot[15121]: go-librespot daemon starting... Jan 25 23:08:31 volumio sudo[15114]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:31 volumio go-librespot[15122]: time="2026-01-25T23:08:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:31 volumio go-librespot[15122]: time="2026-01-25T23:08:31+07:00" level=debug msg="app state loaded" Jan 25 23:08:31 volumio go-librespot[15122]: time="2026-01-25T23:08:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:08:31 volumio volumio[14878]: info: No need to fix Spotify hosts Jan 25 23:08:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=info msg="zeroconf server listening on port 45459" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="obtained new client token: AAAkTEwYvdPoTue5MLCPYi72COB1enKF/QwHnA1iPJpUwHSxbqKbpCeJzB2iLgut/HSkppBzr5f+DfWSfZBpgNw9VoxlBMZjkYslXwzDgHuoQ/iDb+NXhjts79bK+wJq1E9oKdJHclhwVyMTjksxnvY5CByaK0oRVXDcvqRljBhumZeGSsgjqTJp9O3edFDc4pK6MDlfcQNuHHvPn3T+A/qBEVb9o+HcWKYWpbohdKyMM1r2cZonVVPl49E=" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=debug msg="completed challenge" Jan 25 23:08:32 volumio volumio[14878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 23:08:32 volumio volumio[14878]: SPOTIFY: BQD5FNYn-2Xc6BXu4JF9dW3G7egUV_g9F6eQstxf8ANAz2Yky-Xx-Nbe96M4897GJFL0G5kQxHhJdK461TORBd9cgySCswlW78b_lJ8lrYwQvxNd4Rzj0wkS6_tdU7STsR8eKtUzUwyuY3OGZGkng-7mSltVUfacvzP_HZh9fF472m3Vf_rA_1Hk9Y4xnz0rq0BP5FZjWSn3XqcwXKKLz9GBAXotsI0VLaq7OMpngDIJn53_cO3SNtKBz_7GM5Pzcp-e9GrGM4sl3tiTsJeUP-hy8Ab8hfGf4cJpsI96j8OIevRth05mxJT7 Jan 25 23:08:32 volumio volumio[14878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 23:08:32 volumio volumio[14878]: info: New Spotify access token = BQD5FNYn-2Xc6BXu4JF9dW3G7egUV_g9F6eQstxf8ANAz2Yky-Xx-Nbe96M4897GJFL0G5kQxHhJdK461TORBd9cgySCswlW78b_lJ8lrYwQvxNd4Rzj0wkS6_tdU7STsR8eKtUzUwyuY3OGZGkng-7mSltVUfacvzP_HZh9fF472m3Vf_rA_1Hk9Y4xnz0rq0BP5FZjWSn3XqcwXKKLz9GBAXotsI0VLaq7OMpngDIJn53_cO3SNtKBz_7GM5Pzcp-e9GrGM4sl3tiTsJeUP-hy8Ab8hfGf4cJpsI96j8OIevRth05mxJT7 Jan 25 23:08:32 volumio volumio[14878]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 23:08:32 volumio go-librespot[15122]: time="2026-01-25T23:08:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:08:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:32 volumio volumio[14878]: info: Starting Shairport Sync Jan 25 23:08:32 volumio volumio[14878]: info: Starting Shairport Sync Jan 25 23:08:32 volumio volumio[14878]: info: Starting Shairport Sync Jan 25 23:08:32 volumio sudo[15155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 23:08:32 volumio sudo[15155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:32 volumio sudo[15157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 23:08:32 volumio sudo[15157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:32 volumio sudo[15161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 23:08:32 volumio sudo[15161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 23:08:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 23:08:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 23:08:32 volumio systemd[1]: shairport-sync.service: Consumed 2.603s CPU time. Jan 25 23:08:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 23:08:33 volumio sudo[15155]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:33 volumio sudo[15161]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:33 volumio sudo[15157]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:33 volumio volumio[14878]: info: Shairport-Sync Started Jan 25 23:08:33 volumio volumio[14878]: Error adding Membership: Error: addMembership EINVAL Jan 25 23:08:33 volumio volumio[14878]: info: Shairport-Sync Started Jan 25 23:08:33 volumio volumio[14878]: info: Shairport-Sync Started Jan 25 23:08:33 volumio volumio[14878]: info: CoreCommandRouter::volumioGetState Jan 25 23:08:33 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:33 volumio volumio[14878]: 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 25 23:08:33 volumio volumio[14878]: info: Spotify Successfully logged in Jan 25 23:08:33 volumio volumio[14878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:08:33 volumio volumio[14878]: info: [1769357313566] CoreMusicLibrary::Adding element Spotify Jan 25 23:08:33 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:08:33 volumio volumio[14878]: Cannot find translation for source YouTube Music Jan 25 23:08:33 volumio volumio[14878]: Cannot find translation for source Spotify Jan 25 23:08:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:34 volumio volumio[14878]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 23:08:34 volumio volumio[14878]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 23:08:34 volumio volumio[14878]: info: VolumeController:: Volume=100 Mute =false Jan 25 23:08:34 volumio volumio[14878]: info: CoreCommandRouter::volumioGetState Jan 25 23:08:34 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:34 volumio volumio[14878]: info: CoreStateMachine::pushState Jan 25 23:08:34 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:08:34 volumio volumio[14878]: info: CoreCommandRouter::volumioPushState Jan 25 23:08:35 volumio volumio[14878]: info: go-librespot daemon successfully initialized Jan 25 23:08:35 volumio mpd[15106]: 2026-01-25T23:08:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 23:08:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 25 23:08:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 23:08:35 volumio sudo[15060]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:35 volumio sudo[15077]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:35 volumio go-librespot[15197]: go-librespot daemon starting... Jan 25 23:08:35 volumio go-librespot[15199]: time="2026-01-25T23:08:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:35 volumio go-librespot[15199]: time="2026-01-25T23:08:35+07:00" level=debug msg="app state loaded" Jan 25 23:08:35 volumio go-librespot[15199]: time="2026-01-25T23:08:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:36 volumio volumio[14878]: error: MPD error: The expression evaluated to a falsy value: Jan 25 23:08:36 volumio volumio[14878]: assert.ok(self.idling) Jan 25 23:08:36 volumio volumio[14878]: error: The expression evaluated to a falsy value: Jan 25 23:08:36 volumio volumio[14878]: assert.ok(self.idling) Jan 25 23:08:36 volumio volumio[14878]: info: Completed starting Core Plugins Jan 25 23:08:36 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:36 volumio volumio[14878]: info: ----- MyVolumio plugins startup ---- Jan 25 23:08:36 volumio volumio[14878]: info: ------------------------------------------- Jan 25 23:08:36 volumio volumio[14878]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 23:08:36 volumio volumio[14878]: info: MPD running with PID15106 Jan 25 23:08:36 volumio volumio[14878]: ,establishing connection Jan 25 23:08:36 volumio volumio[14878]: error: updateQueue error: null Jan 25 23:08:36 volumio volumio[14878]: error: updateQueue error: null Jan 25 23:08:36 volumio go-librespot[15199]: time="2026-01-25T23:08:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:36 volumio go-librespot[15199]: time="2026-01-25T23:08:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:08:36 volumio go-librespot[15199]: time="2026-01-25T23:08:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:08:36 volumio go-librespot[15199]: time="2026-01-25T23:08:36+07:00" level=info msg="zeroconf server listening on port 34127" Jan 25 23:08:36 volumio go-librespot[15199]: time="2026-01-25T23:08:36+07:00" level=debug msg="obtained new client token: AABifTagTHg/8lTuwMTenYhxR6dFpkRgafZ0G4RVoAN41kEjafAT1Ky95lIBlg6q8yTRBJfo3afySnnA7cEZe1+EvGeBSSk2csGo4b7fA6tW7/8QOm21mzQlD3OZpQtQqBn7mXzoaxJEbhhrRGQQdcvkPB6JBN/mv4wW/8A+3YjqGtfuFsKmjwOpfWQjJfzs9Pt30TwPeartiJ0R0SSX9/iULdR7/mHFnID9Hvzvi70ZnLOeroCF84m+KDA=" Jan 25 23:08:36 volumio go-librespot[15199]: time="2026-01-25T23:08:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:37 volumio go-librespot[15199]: time="2026-01-25T23:08:37+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:37 volumio go-librespot[15199]: time="2026-01-25T23:08:37+07:00" level=debug msg="completed challenge" Jan 25 23:08:37 volumio go-librespot[15199]: time="2026-01-25T23:08:37+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 25 23:08:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:38 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:38 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 25 23:08:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:40 volumio go-librespot[15207]: go-librespot daemon starting... Jan 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+07:00" level=debug msg="app state loaded" Jan 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:40 volumio volumio[14878]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+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 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+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 25 23:08:40 volumio go-librespot[15208]: time="2026-01-25T23:08:40+07:00" level=info msg="zeroconf server listening on port 36327" Jan 25 23:08:41 volumio go-librespot[15208]: time="2026-01-25T23:08:41+07:00" level=debug msg="obtained new client token: AADt6ZbQpaqILuEl6SFuKYbhAcOSm/A/o6tBS1Wb3WqT8usx++pCu1f3gD2mVY9Du3ITfcD8qQaqF77G/YE/ejjNKUff6I/DVtpF6tioAg3kI3zIh7oUz4ahsxYlYXt1EaeusVC8H0RZdkKzAOJbW1Lfc7ANRPDsHjpEJQEHIg0o0NBjaTEnrCy05PswqBcfWIZAeT8ifZphkfMMvScif3YbpxDsueiJaXyyJtSci740KxAMWimESh8q" Jan 25 23:08:41 volumio go-librespot[15208]: time="2026-01-25T23:08:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:41 volumio go-librespot[15208]: time="2026-01-25T23:08:41+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:41 volumio go-librespot[15208]: time="2026-01-25T23:08:41+07:00" level=debug msg="completed challenge" Jan 25 23:08:41 volumio go-librespot[15208]: time="2026-01-25T23:08:41+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 25 23:08:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:41 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:41 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:44 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:44 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 25 23:08:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:44 volumio go-librespot[15216]: go-librespot daemon starting... Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 23:08:44 volumio go-librespot[15217]: time="2026-01-25T23:08:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:44 volumio go-librespot[15217]: time="2026-01-25T23:08:44+07:00" level=debug msg="app state loaded" Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 23:08:44 volumio go-librespot[15217]: time="2026-01-25T23:08:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 23:08:44 volumio volumio[14878]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+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 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+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 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+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 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+07:00" level=info msg="zeroconf server listening on port 44915" Jan 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+07:00" level=debug msg="obtained new client token: AABW2Y4FEQZScutHddY9v+C6VFeVrslkSHMtj7gzcR49+RdL1svbjvibijHkmsYUDNaqVoVxU+Sho9AAcUdycVsm8oq5it72yX8EWNQDhLFKWL1suaiscXj5erW8F31sQXMqvR14boz1BLWs2TkWtO94uWn3M/fiWiCZpziWoG0Y+9tI6P97THrVOMgRgplX0+YhklO3a7ah1BR5synzbZf6uLMpjX9w3EMRk/QrD6EKnT0CR1ew7dFMcd4=" Jan 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+07:00" level=debug msg="completed challenge" Jan 25 23:08:45 volumio go-librespot[15217]: time="2026-01-25T23:08:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:08:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:46 volumio volumio[14878]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 23:08:46 volumio volumio[14878]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 23:08:46 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:46 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:46 volumio volumio[14878]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 23:08:46 volumio volumio[14878]: info: MyVolumio login type: Token Jan 25 23:08:46 volumio volumio[14878]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 23:08:46 volumio volumio[14878]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 23:08:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:48 volumio volumio[14878]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 23:08:48 volumio volumio[14878]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 23:08:48 volumio volumio[14878]: info: Streaming services startup Jan 25 23:08:48 volumio volumio[14878]: info: Starting Streaming Daemon Jan 25 23:08:48 volumio sudo[15240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 23:08:48 volumio volumio[14878]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 23:08:48 volumio sudo[15240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:48 volumio sudo[15240]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:48 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:48 volumio volumio[14878]: error: Cannot start Volumio Streaming Daemon Jan 25 23:08:48 volumio volumio[14878]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 23:08:48 volumio volumio[14878]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 23:08:48 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 25 23:08:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:49 volumio go-librespot[15246]: go-librespot daemon starting... Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=debug msg="app state loaded" Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+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 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+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 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=info msg="zeroconf server listening on port 41223" Jan 25 23:08:49 volumio volumio[14878]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=debug msg="obtained new client token: AAAA9sEXIwbDO6DRBHSNaSyeGbhF2MXB33v64utIE34dATlFpENgVaqoOlak3tGLcANflWazu+FoQp4blgbtir2OlkzEaVjcBVVADsPHXe1Y91HK+E2nMfXyatuQganHXnhJ7epdh4SRYYgJFayQSM/Qk0zO/NOJdbFIVE1ao33iVVuns7VzAk9emCUaq65KIk1pQ3cH107gyCcgDhfxVVyGJqmhSOa8+UVcoZ3AG4adPZExfgeltPcD28w=" Jan 25 23:08:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:49 volumio go-librespot[15247]: time="2026-01-25T23:08:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:50 volumio go-librespot[15247]: time="2026-01-25T23:08:50+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:50 volumio go-librespot[15247]: time="2026-01-25T23:08:50+07:00" level=debug msg="completed challenge" Jan 25 23:08:50 volumio go-librespot[15247]: time="2026-01-25T23:08:50+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 25 23:08:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:50 volumio volumio[14878]: info: MyVolumio token set successfully Jan 25 23:08:50 volumio volumio[14878]: info: MYVOLUMIO: Adding device Jan 25 23:08:50 volumio volumio[14878]: info: MYVOLUMIO: Evaluating Server Jan 25 23:08:51 volumio volumio[14878]: info: MyVolumio status changed Jan 25 23:08:51 volumio volumio[14878]: info: Streaming services startup Jan 25 23:08:51 volumio volumio[14878]: info: Starting Streaming Daemon Jan 25 23:08:51 volumio volumio[14878]: info: Removing browser output: myVolumio user plan is not superstar Jan 25 23:08:51 volumio volumio[14878]: info: Removing audio output: Jan 25 23:08:51 volumio volumio[14878]: info: Stoppping Tunnel 1 Jan 25 23:08:51 volumio sudo[15275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 23:08:51 volumio sudo[15275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:51 volumio sudo[15275]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:51 volumio sudo[15278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 25 23:08:51 volumio sudo[15278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:08:51 volumio volumio[14878]: error: Cannot start Volumio Streaming Daemon Jan 25 23:08:51 volumio volumio[14878]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 23:08:51 volumio volumio[14878]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 23:08:51 volumio sudo[15278]: pam_unix(sudo:session): session closed for user root Jan 25 23:08:51 volumio volumio[14878]: info: Remote SSH Stopped Jan 25 23:08:51 volumio volumio[14878]: info: Setting Geolocation for MyVolumio to as1 Jan 25 23:08:51 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:51 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:51 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:51 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:51 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:51 volumio volumio[14878]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 25 23:08:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:52 volumio volumio[14878]: info: Updating MyVolumio device info Jan 25 23:08:52 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:52 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:52 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:52 volumio volumio[14878]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 25 23:08:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 25 23:08:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:53 volumio go-librespot[15280]: go-librespot daemon starting... Jan 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+07:00" level=debug msg="app state loaded" Jan 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+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 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+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 25 23:08:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:53 volumio go-librespot[15281]: time="2026-01-25T23:08:53+07:00" level=info msg="zeroconf server listening on port 46337" Jan 25 23:08:54 volumio go-librespot[15281]: time="2026-01-25T23:08:54+07:00" level=debug msg="obtained new client token: AADZJaEv3pQ+qBhHdTG7a/Te+2h/3egVXYkBGJTT9YZlmVJwB8alpDi1mfRlZC4va6eKWEKy7gN2PORk86R6HROAHWqSowLCYRXLtDj2QEBtUKXjeMdinR7JFqF+h22ELeqgGq9eIsqGKOOiIt8rqd5ZGb9wS4xWrrLzTCnlPsRDrrJkRvIPne8doSwJGOw5gcffn73ptTWP0KQkO08WEP31t3/m71LHQALVv4vY9rjU0+7ANqY1xI/+R1g=" Jan 25 23:08:54 volumio go-librespot[15281]: time="2026-01-25T23:08:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:54 volumio go-librespot[15281]: time="2026-01-25T23:08:54+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:54 volumio go-librespot[15281]: time="2026-01-25T23:08:54+07:00" level=debug msg="completed challenge" Jan 25 23:08:54 volumio go-librespot[15281]: time="2026-01-25T23:08:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:08:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:54 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:54 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:55 volumio volumio[14878]: info: MYVOLUMIO: Adding device Jan 25 23:08:55 volumio volumio[14878]: info: MYVOLUMIO: Evaluating Server Jan 25 23:08:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:56 volumio volumio[14878]: info: Setting Geolocation for MyVolumio to as1 Jan 25 23:08:56 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:56 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:56 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:57 volumio volumio[14878]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 25 23:08:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 25 23:08:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:08:57 volumio go-librespot[15320]: go-librespot daemon starting... Jan 25 23:08:57 volumio volumio[14878]: info: Updating MyVolumio device info Jan 25 23:08:57 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:57 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:57 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:57 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:08:57 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:08:57 volumio go-librespot[15321]: time="2026-01-25T23:08:57+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:08:57 volumio go-librespot[15321]: time="2026-01-25T23:08:57+07:00" level=debug msg="app state loaded" Jan 25 23:08:57 volumio go-librespot[15321]: time="2026-01-25T23:08:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:08:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:08:58 volumio volumio[14878]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+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 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+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 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+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 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+07:00" level=info msg="zeroconf server listening on port 42641" Jan 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+07:00" level=debug msg="obtained new client token: AACxDsD3Lc+Nz3Td0wpaUIeGxbaWw/j0SLrgM3m1BU6m5YiQcIA01f3hXndEVwHGiSgH7bBH86BI2J88c9w2mAj+a1PqSON3D9ze2N/jrOpG8cXTpegwACNkqNyJbpKEv4MuW/pgb4zUDMGSCkCK7XijVNbKXnpyZ3xfyFz6y/7W+o7CrDfRWE0dTHRU3R1OU9wglWn57v03dNfvW/UTiSvhT9TIVEZhcIXjcL0V3ixvWN3/shWPG/zt" Jan 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+07:00" level=debug msg="completed keyexchange" Jan 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+07:00" level=debug msg="completed challenge" Jan 25 23:08:58 volumio go-librespot[15321]: time="2026-01-25T23:08:58+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 25 23:08:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:08:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:08:59 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:08:59 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:08:59 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 23:08:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:08:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:08:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:00 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 25 23:09:00 volumio volumio-remote-updater[628]: Test mode disabled Jan 25 23:09:00 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 25 23:09:00 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 25 23:09:00 volumio volumio[14878]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 25 23:09:00 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 25 23:09:00 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:00 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:09:01 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 25 23:09:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 25 23:09:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:01 volumio volumio[14878]: 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 25 23:09:01 volumio volumio[14878]: info: CoreCommandRouter::volumioGetState Jan 25 23:09:01 volumio volumio[14878]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:01 volumio go-librespot[15332]: go-librespot daemon starting... Jan 25 23:09:01 volumio go-librespot[15333]: time="2026-01-25T23:09:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:01 volumio go-librespot[15333]: time="2026-01-25T23:09:01+07:00" level=debug msg="app state loaded" Jan 25 23:09:01 volumio go-librespot[15333]: time="2026-01-25T23:09:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+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 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+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 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=info msg="zeroconf server listening on port 43417" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=debug msg="obtained new client token: AAAYld1yPi24HB2BVyLtQBIaUS4KEtJPSdb33+svd3WtOB8FXnLV9aexNetOWeEHFhvlA/yqTl/lQIgy447IWQFTfzFE6IKwC1Nrx5me2eQL9eIZi/MzFxYi5DKJMnCbN5Ju0UtSTAu3G77o1pVqVdGBhloSluTHx97smKfvncizUP8kJpOamKdttbPRGn8lVFWh1+ROfw7+G2JunKeWGSu+v/o7iT96aK9raNVfF25vbQBRxijXh59aUQk=" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+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 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=debug msg="completed challenge" Jan 25 23:09:02 volumio go-librespot[15333]: time="2026-01-25T23:09:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:03 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:03 volumio volumio[14878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:09:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 25 23:09:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:06 volumio go-librespot[15355]: go-librespot daemon starting... Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="app state loaded" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 25 23:09:06 volumio volumio[14878]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=info msg="zeroconf server listening on port 41847" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="new websocket client" Jan 25 23:09:06 volumio volumio[14878]: info: Connection to go-librespot Websocket established Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::volumioGetBrowseSources Jan 25 23:09:06 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="obtained new client token: AAB+kEdmXKxhd5aNubFFYXm72/7lTVgPW7qS+yeY2EATgGoZ33SLQIwboi3rt/p2217WPcuXHTyE1AH0DmhZaKLwnImRqZdvF6F6sq8T+1Y9zhV1OEIyL0aZHP5J60ENBX2JSIUQzl5WC3TeMZnrQpashspFKr8hEJofISxlie1WEuD7VJ5fL2XlkKDjTWzpFX8VnHr7uYeP1oI9Z2lBW//4SmVi0bpyksJaZZCrzLYFeh+ha+druw0VQBQ=" Jan 25 23:09:06 volumio go-librespot[15356]: time="2026-01-25T23:09:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:07 volumio go-librespot[15356]: time="2026-01-25T23:09:07+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:07 volumio go-librespot[15356]: time="2026-01-25T23:09:07+07:00" level=debug msg="completed challenge" Jan 25 23:09:07 volumio go-librespot[15356]: time="2026-01-25T23:09:07+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 25 23:09:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:07 volumio volumio[14878]: info: Connection to go-librespot Websocket closed Jan 25 23:09:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:08 volumio volumio[14878]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jan 25 23:09:08 volumio volumio[14878]: info: Completed starting MyVolumio Plugin Jan 25 23:09:08 volumio volumio[14878]: [Metrics] CommandRouter: 57s 146.77ms Jan 25 23:09:08 volumio volumio[14878]: info: CoreCommandRouter::volumiosetStartupVolume Jan 25 23:09:08 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:08 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:08 volumio volumio[14878]: info: CoreCommandRouter::Close All Modals sent Jan 25 23:09:08 volumio volumio[14878]: info: CoreCommandRouter::Close All Modals sent Jan 25 23:09:09 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 25 23:09:09 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 25 23:09:09 volumio volumio[14878]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 25 23:09:09 volumio volumio[14878]: info: Getting Spotify volume Jan 25 23:09:09 volumio volumio[14878]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 23:09:09 volumio volumio[14878]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:09:09 volumio volumio[14878]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 23:09:09 volumio volumio[14878]: errno: -111, Jan 25 23:09:09 volumio volumio[14878]: code: 'ECONNREFUSED', Jan 25 23:09:09 volumio volumio[14878]: syscall: 'connect', Jan 25 23:09:09 volumio volumio[14878]: address: '127.0.0.1', Jan 25 23:09:09 volumio volumio[14878]: port: 9879, Jan 25 23:09:09 volumio volumio[14878]: response: undefined Jan 25 23:09:09 volumio volumio[14878]: } Jan 25 23:09:09 volumio volumio[14878]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 23:09:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 25 23:09:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:10 volumio go-librespot[15379]: go-librespot daemon starting... Jan 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+07:00" level=debug msg="app state loaded" Jan 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+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 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+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 25 23:09:10 volumio go-librespot[15380]: time="2026-01-25T23:09:10+07:00" level=info msg="zeroconf server listening on port 39517" Jan 25 23:09:11 volumio sudo[15389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 23:08' Jan 25 23:09:11 volumio sudo[15389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:11 volumio go-librespot[15380]: time="2026-01-25T23:09:11+07:00" level=debug msg="obtained new client token: AAD0eKwRAtc7WCJWBrO/dq2w5v9IneImlLPUddR9NvV3jmofZWf3vNkoDtNxbXvUldh0UKYj0PyuwvLKciEYRZUqiyn5iYMUS1s4YeB3z1UZsEYLkFxO6IaWMsK8YQmiRYyF8ExOpTQf4wD6AOWbaaKwA6RQ8WY6oCjM8tMIUnJd5XdpJXnF3dUJ66a2SXZa8jOTUZFAUGkawLoO1v2ArqVs3yiPdgAt+toDGzpmGjjZAMTNlmRtnzJe" Jan 25 23:09:11 volumio go-librespot[15380]: time="2026-01-25T23:09:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:11 volumio go-librespot[15380]: time="2026-01-25T23:09:11+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:11 volumio go-librespot[15380]: time="2026-01-25T23:09:11+07:00" level=debug msg="completed challenge" Jan 25 23:09:11 volumio sudo[15389]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:11 volumio go-librespot[15380]: time="2026-01-25T23:09:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:11 volumio volumio-remote-updater[628]: [2026-01-25 23:09:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 23:09:11 volumio volumio-remote-updater[628]: [2026-01-25 23:09:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 23:09:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 23:09:11 volumio systemd[1]: volumio.service: Consumed 1min 6.784s CPU time. Jan 25 23:09:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 23:09:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 23:09:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6134. Jan 25 23:09:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 23:09:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 23:09:11 volumio systemd[1]: volumio.service: Consumed 1min 6.784s CPU time. Jan 25 23:09:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 23:09:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 23:09:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 25 23:09:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:14 volumio go-librespot[15418]: go-librespot daemon starting... Jan 25 23:09:14 volumio go-librespot[15419]: time="2026-01-25T23:09:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:14 volumio go-librespot[15419]: time="2026-01-25T23:09:14+07:00" level=debug msg="app state loaded" Jan 25 23:09:14 volumio go-librespot[15419]: time="2026-01-25T23:09:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:15 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+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 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+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 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+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 25 23:09:15 volumio volumio[15402]: info: ----- Volumio3 ---- Jan 25 23:09:15 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:15 volumio volumio[15402]: info: ----- System startup ---- Jan 25 23:09:15 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+07:00" level=info msg="zeroconf server listening on port 41817" Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+07:00" level=debug msg="obtained new client token: AACLSAW6jXbOqJDKuBhV3AzCJmAIVrMasbNHcOSoR/4qCGVLpIWxC5vv+HYg00hWJ2GAgqQvpwKmZlSGMbKux5malwfE72zuWs2C45iWs1w4TF69BltiXOyfhaifbNGrEaZDgfOwq57ttYq4ERHm/XDZyhPZcq/5tD0mldfb8jcLphhYwF+MwzXfWGeNoF3SWJAIW1HBh07eMRS9icxvSo4MIDjsff6cingQJhIZyYyUeYeMusJedyfDu1A=" Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+07:00" level=debug msg="completed challenge" Jan 25 23:09:15 volumio go-librespot[15419]: time="2026-01-25T23:09:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:16 volumio volumio-remote-updater[628]: [2026-01-25 23:09:16] [connect] Successful connection Jan 25 23:09:16 volumio volumio[15402]: info: MYVOLUMIO Environment detected Jan 25 23:09:16 volumio volumio[15402]: info: Plugin folders cleanup Jan 25 23:09:16 volumio volumio[15402]: info: Scanning into folder /volumio/app/plugins/ Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category audio_interface Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category miscellanea Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category music_service Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category plugins.json Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category system_controller Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category user_interface Jan 25 23:09:16 volumio volumio[15402]: info: Scanning into folder /data/plugins/ Jan 25 23:09:16 volumio volumio[15402]: info: Scanning category music_service Jan 25 23:09:16 volumio volumio[15402]: info: Plugin folders cleanup completed Jan 25 23:09:16 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:16 volumio volumio[15402]: info: ----- Core plugins startup ---- Jan 25 23:09:16 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:16 volumio volumio[15402]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 23:09:16 volumio volumio[15402]: info: Adding plugin upnp to MyMusic Plugins Jan 25 23:09:16 volumio volumio[15402]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 23:09:16 volumio volumio[15402]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 23:09:16 volumio volumio[15402]: info: Loading plugins from folder /data/plugins/ Jan 25 23:09:16 volumio volumio[15402]: info: Loading plugin "system"... Jan 25 23:09:17 volumio volumio[15402]: info: Loading plugin "appearance"... Jan 25 23:09:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:18 volumio volumio[15402]: info: Loading plugin "network"... Jan 25 23:09:18 volumio volumio[15402]: info: Refreshing Cached IP Addresses Jan 25 23:09:18 volumio sudo[15439]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 23:09:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 25 23:09:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:18 volumio sudo[15439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:19 volumio sudo[15439]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:19 volumio sudo[15441]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 23:09:19 volumio sudo[15441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "services"... Jan 25 23:09:19 volumio sudo[15441]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "alsa_controller"... Jan 25 23:09:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:19 volumio go-librespot[15450]: go-librespot daemon starting... Jan 25 23:09:19 volumio sudo[15449]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 23:09:19 volumio sudo[15449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+07:00" level=debug msg="app state loaded" Jan 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:19 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "wizard"... Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "networkfs"... Jan 25 23:09:19 volumio volumio[15402]: info: Starting Udev Watcher for removable devices Jan 25 23:09:19 volumio volumio[15402]: info: Ignoring mount for partition: boot Jan 25 23:09:19 volumio volumio[15402]: info: Ignoring mount for partition: volumio Jan 25 23:09:19 volumio volumio[15402]: info: Ignoring mount for partition: volumio_data Jan 25 23:09:19 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "volumio_command_line_client"... Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "upnp"... Jan 25 23:09:19 volumio volumio[15402]: info: [1769357359378] Starting Upmpd Daemon Jan 25 23:09:19 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "my_music"... Jan 25 23:09:19 volumio volumio[15402]: info: Loading plugin "mpd"... Jan 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+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 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+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 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+07:00" level=info msg="zeroconf server listening on port 35981" Jan 25 23:09:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:19 volumio go-librespot[15460]: time="2026-01-25T23:09:19+07:00" level=debug msg="obtained new client token: AACu5UdUkSIebQLkbvg9crI0HTU3CbIwVxEaVsYnGGPn94wsGVjfNuDbykC/9/lCjjT1euwDzJhonI/bC1F5+YSwNqYddvUmoISIkagz3wAYy2EXDlUjqISedjhRdO+9U/YqrOfdtcPN1Gm2qIbPIjfmW8GMqVyIqsFGyXc91KhHKOwAGFue8etmLMaL9iXl9S2Wha88iZWds4dIUmI5ZTkKE3LbTapReB4yUIHi+252G30rs8zoYMP4m/E=" Jan 25 23:09:20 volumio go-librespot[15460]: time="2026-01-25T23:09:20+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 25 23:09:20 volumio volumio[15402]: info: Loading plugin "upnp_browser"... Jan 25 23:09:20 volumio go-librespot[15460]: time="2026-01-25T23:09:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 23:09:20 volumio go-librespot[15460]: time="2026-01-25T23:09:20+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:20 volumio go-librespot[15460]: time="2026-01-25T23:09:20+07:00" level=debug msg="completed challenge" Jan 25 23:09:20 volumio go-librespot[15460]: time="2026-01-25T23:09:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:21 volumio sudo[15449]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:23 volumio volumio[15402]: info: Starting UPNP Browser Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "alarm-clock"... Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "airplay_emulation"... Jan 25 23:09:23 volumio volumio[15402]: info: Starting Shairport Sync Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "last_100"... Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "webradio"... Jan 25 23:09:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jan 25 23:09:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:23 volumio go-librespot[15482]: go-librespot daemon starting... Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "i2s_dacs"... Jan 25 23:09:23 volumio go-librespot[15483]: time="2026-01-25T23:09:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:23 volumio go-librespot[15483]: time="2026-01-25T23:09:23+07:00" level=debug msg="app state loaded" Jan 25 23:09:23 volumio go-librespot[15483]: time="2026-01-25T23:09:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "volumiodiscovery"... Jan 25 23:09:23 volumio volumio[15402]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 23:09:23 volumio volumio[15402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:09:23 volumio volumio[15402]: *** WARNING *** For more information see Jan 25 23:09:23 volumio volumio[15402]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 23:09:23 volumio volumio[15402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:09:23 volumio node[15402]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 23:09:23 volumio volumio[15402]: *** WARNING *** For more information see Jan 25 23:09:23 volumio node[15402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:09:23 volumio node[15402]: *** WARNING *** For more information see Jan 25 23:09:23 volumio node[15402]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 23:09:23 volumio node[15402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 23:09:23 volumio node[15402]: *** WARNING *** For more information see Jan 25 23:09:23 volumio volumio[15402]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 23:09:23 volumio volumio[15402]: info: Discovery: Started advertising with name: Volumio Jan 25 23:09:23 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 23:09:23 volumio volumio[15402]: info: Loading plugin "spop"... Jan 25 23:09:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+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 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+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 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+07:00" level=info msg="zeroconf server listening on port 37913" Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+07:00" level=debug msg="obtained new client token: AAAIOTUZosrJJI2uTeyHMaDMXl6mCtVaQVb8GnlY5h0WfQ9arfARIjZXWK6uBmuJFsHJoS7xYyB95s0LYFY02hFNxrxotxBiLqMubwrXckf0ZSysmIsbPSrjarJwMzbQO1VsWtINNhgEaWuaGGFWZdHE2NhB1cxnZlDi4jZ8QCXaabAcSJD67pOjOYtM6Sc47B6OXuq70vqcmfZG1wgqL+ZDkodgSJEqCHMbH766waGGPYvsHUImP3NTuUo=" Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+07:00" level=debug msg="completed challenge" Jan 25 23:09:24 volumio go-librespot[15483]: time="2026-01-25T23:09:24+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 25 23:09:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:25 volumio volumio[15402]: info: Loading plugin "ytcr"... Jan 25 23:09:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Jan 25 23:09:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:28 volumio go-librespot[15492]: go-librespot daemon starting... Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=debug msg="app state loaded" Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:28 volumio volumio[15402]: info: Loading plugin "ytmusic"... Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=info msg="zeroconf server listening on port 37309" Jan 25 23:09:28 volumio go-librespot[15493]: time="2026-01-25T23:09:28+07:00" level=debug msg="obtained new client token: AAC5jbgqikbPwhnGYPEkZMlDIku6HprDZLuMJz4uZka16+i2mmuSZ7ZCko9UyaRiKvUHMmOuF0zCrwCx2KJrikVLbQvSD7KHiyh3FDh6ItTgekYKL9TvJi3ThnFKDN+51PpekArjaOGraUDJ09f3mgH3hfPdBztUJeisCcbGN26kyw20QXOFNprWHQdVfAzSOHjni3QXjY5wSSuG6h4fmDetct1jjbfjchEBUyKcvCiBBe7kUeoSZkp7ZuU=" Jan 25 23:09:29 volumio go-librespot[15493]: time="2026-01-25T23:09:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:29 volumio volumio-remote-updater[628]: [2026-01-25 23:09:29] [connect] Successful connection Jan 25 23:09:29 volumio go-librespot[15493]: time="2026-01-25T23:09:29+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:29 volumio go-librespot[15493]: time="2026-01-25T23:09:29+07:00" level=debug msg="completed challenge" Jan 25 23:09:29 volumio go-librespot[15493]: time="2026-01-25T23:09:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "outputs"... Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "albumart"... Jan 25 23:09:29 volumio volumio[15402]: info: Plugin example_plugin is not enabled Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "inputs"... Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "updater_comm"... Jan 25 23:09:29 volumio volumio[15402]: info: Plugin mpdemulation is not enabled Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "rest_api"... Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "websocket"... Jan 25 23:09:29 volumio volumio[15402]: info: Starting Socket.io Server version 1.7.4 Jan 25 23:09:29 volumio volumio[15402]: info: Loading plugin "RoonBridge"... Jan 25 23:09:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:30 volumio volumio[15402]: info: Applying required configuration parameters for plugin RoonBridge Jan 25 23:09:30 volumio volumio[15402]: info: Loading i18n strings for locale en Jan 25 23:09:30 volumio volumio[15402]: Updating browse sources language Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:09:30 volumio volumio[15514]: Forking 3 albumart workers Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::initPlayerControls Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 23:09:30 volumio volumio[15402]: Express server listening on port 3000 Jan 25 23:09:30 volumio volumio[15402]: [Metrics] WebUI: 16s 154.77ms Jan 25 23:09:30 volumio volumio[15402]: info: CoreStateMachine::resetVolumioState Jan 25 23:09:30 volumio volumio[15402]: info: CoreStateMachine::getcurrentVolume Jan 25 23:09:30 volumio volumio[15402]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 23:09:30 volumio sudo[15557]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 23:09:30 volumio sudo[15557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:30 volumio volumio[15402]: info: Volumio Network Manager: Network status updated: 1 Jan 25 23:09:30 volumio sudo[15557]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:30 volumio sudo[15559]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 23:09:30 volumio sudo[15559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:30 volumio sudo[15559]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:31 volumio volumio[15402]: info: VolumeController:: Volume=100 Mute =false Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::pushState Jan 25 23:09:31 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::volumioPushState Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::updateTrackBlock Jan 25 23:09:31 volumio volumio[15402]: info: CorePlayQueue::getTrackBlock Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 23:09:31 volumio volumio-remote-updater[628]: [2026-01-25 23:09:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769357369 101 Jan 25 23:09:31 volumio volumio[15402]: 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 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:31 volumio volumio[15402]: info: Reloading queue from file Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::setRepeat null single undefined Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::pushState Jan 25 23:09:31 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::volumioPushState Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::setRandom null Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::pushState Jan 25 23:09:31 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::volumioPushState Jan 25 23:09:31 volumio volumio[15402]: info: Setting Device type: Raspberry PI Jan 25 23:09:31 volumio volumio[15402]: info: Completed loading Core Plugins Jan 25 23:09:31 volumio volumio[15402]: info: Preparing to generate the ALSA configuration file Jan 25 23:09:31 volumio volumio[15402]: info: VolumeController:: Volume=100 Mute =false Jan 25 23:09:31 volumio volumio[15402]: info: CoreStateMachine::pushState Jan 25 23:09:31 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::volumioPushState Jan 25 23:09:31 volumio volumio[15402]: info: Asound.conf file unchanged, so no further update is needed Jan 25 23:09:31 volumio volumio[15402]: info: Output device has changed, restarting MPD Jan 25 23:09:31 volumio volumio[15402]: info: Output device has changed, restarting Shairport Sync Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:31 volumio sudo[15575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 23:09:31 volumio sudo[15575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:31 volumio sudo[15577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 23:09:31 volumio sudo[15577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:31 volumio volumio[15402]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 23:09:31 volumio volumio[15402]: info: ___________ START PLUGINS ___________ Jan 25 23:09:31 volumio sudo[15579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 23:09:31 volumio sudo[15579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:31 volumio volumio[15402]: info: ControllerMpd::onStart: Initializing MPD Jan 25 23:09:31 volumio sudo[15577]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:31 volumio volumio[15402]: info: Creating MPD Configuration file Jan 25 23:09:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 23:09:31 volumio sudo[15575]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:09:31 volumio volumio[15402]: info: [1769357371992] CoreMusicLibrary::Adding element Media Servers Jan 25 23:09:31 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:09:32 volumio volumio[15402]: info: UPNP Browser: Client initialized successfully Jan 25 23:09:32 volumio sudo[15588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 23:09:32 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 23:09:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 23:09:32 volumio systemd[1]: mpd.service: Consumed 7.276s CPU time. Jan 25 23:09:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 23:09:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 23:09:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 23:09:32 volumio sudo[15590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 23:09:32 volumio sudo[15588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:32 volumio sudo[15590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:32 volumio sudo[15588]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 23:09:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 23:09:32 volumio volumio[15402]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:32 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 23:09:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 23:09:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Jan 25 23:09:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 23:09:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 23:09:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 23:09:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 23:09:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:32 volumio volumio[15402]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 23:09:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:09:32 volumio volumio[15402]: info: [1769357372360] CoreMusicLibrary::Adding element Last_100 Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:09:32 volumio go-librespot[15604]: go-librespot daemon starting... Jan 25 23:09:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:09:32 volumio volumio[15402]: info: [1769357372388] CoreMusicLibrary::Adding element Webradio Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:09:32 volumio volumio[15402]: info: Initializing BBC Radios Jan 25 23:09:32 volumio go-librespot[15606]: time="2026-01-25T23:09:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:32 volumio go-librespot[15606]: time="2026-01-25T23:09:32+07:00" level=debug msg="app state loaded" Jan 25 23:09:32 volumio go-librespot[15606]: time="2026-01-25T23:09:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:32 volumio volumio[15402]: info: Creating Spotify config file Jan 25 23:09:32 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:32 volumio sudo[15605]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 23:09:32 volumio sudo[15605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 23:09:32 volumio sudo[15605]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+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 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+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 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=info msg="zeroconf server listening on port 38221" Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=debug msg="obtained new client token: AACeescZDT2VsBJzJl0BvvnaFD49m/WGmZkZFZLWX9LIg7AkIZM/b4KbPqRTIR3Q/aDVeBERgnrdgYTiSlioTty6jzQDG4zqfVvMz8Eug0Gq4LVV30J9kr6Xn2cNIr3DA8WmUHhYtWMuRkjmugyq0gci2x2wK7vCeWWa41W7E7czDB5uf/rSn+0dNm30tGmzyy+cOtl3E8EqHUP+9h6K1k0A92BbJhqqk/csUzKqiQ2EU9EcBc5+VU4Ph0Q=" Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:33 volumio volumio[15402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:09:33 volumio volumio[15402]: info: [1769357373678] CoreMusicLibrary::Adding element YouTube Music Jan 25 23:09:33 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=debug msg="completed challenge" Jan 25 23:09:33 volumio volumio[15402]: Cannot find translation for source YouTube Music Jan 25 23:09:33 volumio volumio[15402]: info: Volumio Calling Home Jan 25 23:09:33 volumio go-librespot[15606]: time="2026-01-25T23:09:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:33 volumio sudo[15630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 25 23:09:33 volumio sudo[15630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:33 volumio volumio[15524]: Starting albumart workers Jan 25 23:09:33 volumio sudo[15630]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:34 volumio volumio[15526]: Starting albumart workers Jan 25 23:09:34 volumio volumio[15525]: Starting albumart workers Jan 25 23:09:34 volumio volumio[15402]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 23:09:34 volumio volumio[15402]: info: Discovery: Found device Volumio Jan 25 23:09:34 volumio volumio[15402]: info: CoreCommandRouter::volumioGetState Jan 25 23:09:34 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:34 volumio volumio[15402]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 23:09:34 volumio volumio[15402]: info: Discovery: Found device Volumio Jan 25 23:09:34 volumio volumio[15402]: info: CoreCommandRouter::volumioGetState Jan 25 23:09:34 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:34 volumio volumio[15402]: info: MPD Permissions set Jan 25 23:09:34 volumio volumio[15402]: info: MPD Permissions set Jan 25 23:09:34 volumio volumio[15402]: info: Upmpdcli Daemon Started Jan 25 23:09:34 volumio volumio[15402]: info: Volumio called home Jan 25 23:09:34 volumio volumio[15402]: info: Spotify config file written Jan 25 23:09:34 volumio sudo[15637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 23:09:34 volumio sudo[15637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:35 volumio go-librespot[15639]: go-librespot daemon starting... Jan 25 23:09:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:35 volumio volumio[15402]: 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 25 23:09:35 volumio sudo[15637]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:35 volumio go-librespot[15640]: time="2026-01-25T23:09:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:35 volumio go-librespot[15640]: time="2026-01-25T23:09:35+07:00" level=debug msg="app state loaded" Jan 25 23:09:35 volumio go-librespot[15640]: time="2026-01-25T23:09:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 23:09:35 volumio volumio[15402]: info: No need to fix Spotify hosts Jan 25 23:09:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:35 volumio go-librespot[15640]: time="2026-01-25T23:09: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:35 volumio go-librespot[15640]: time="2026-01-25T23:09:35+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 25 23:09:35 volumio go-librespot[15640]: time="2026-01-25T23:09:35+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 25 23:09:36 volumio go-librespot[15640]: time="2026-01-25T23:09:36+07:00" level=info msg="zeroconf server listening on port 46703" Jan 25 23:09:36 volumio go-librespot[15640]: time="2026-01-25T23:09:36+07:00" level=debug msg="obtained new client token: AADrL7BJT755HnpiAcv3mALw+5AD22sJsA+bVU6fQGv6eqFbRkiw4WolAbUzHgcE5itGTBeWsD7zlOf3hRUyNfzGWQc3NWHV9Rx+xxaP/T8/CKFaDqTfgow7suGtcWn5CJE5YXSQWZBSglCzj3eyCsrOKuGBwvybETyesOPdE0NvQrWTgDQxLUMBtnuWxI5nTlRsJJgwqZGtvBNrr/LXkqGl/cA2ThvT/MOC68kJKS6FkaZjoR5hSlkd" Jan 25 23:09:36 volumio go-librespot[15640]: time="2026-01-25T23:09:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:36 volumio go-librespot[15640]: time="2026-01-25T23:09:36+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:36 volumio go-librespot[15640]: time="2026-01-25T23:09:36+07:00" level=debug msg="completed challenge" Jan 25 23:09:36 volumio volumio[15402]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 23:09:36 volumio volumio[15402]: SPOTIFY: BQB_YPcSJD6qiz5sh2d8SJx8BqgVwji4ciqD0MR18UK8ww8jgGDSZHjd-1wKcKSFsr07APY8Dko0HxbWSMXzQpJO0g0TBHeqdHaC9FCahasVQp6tQTEiOBjA191nUQn8RJKGmxPNXurp5M_x3S6qQ7i_QA350_ilveXfB99fZVGL2BGKd7zQ3Ek-oCAVfaWGgufGQnH5NGQ59uPL8MeGoQQn05QzsLCTts_tlCNFLFLoWLWNP_vNs0P0rGYDC_9N_VS5th4-tq_zS_gV5PSo7n9RKD65_rtdpTF8NGx4kS9Bk1OeH8p6e5XE Jan 25 23:09:36 volumio volumio[15402]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 23:09:36 volumio volumio[15402]: info: New Spotify access token = BQB_YPcSJD6qiz5sh2d8SJx8BqgVwji4ciqD0MR18UK8ww8jgGDSZHjd-1wKcKSFsr07APY8Dko0HxbWSMXzQpJO0g0TBHeqdHaC9FCahasVQp6tQTEiOBjA191nUQn8RJKGmxPNXurp5M_x3S6qQ7i_QA350_ilveXfB99fZVGL2BGKd7zQ3Ek-oCAVfaWGgufGQnH5NGQ59uPL8MeGoQQn05QzsLCTts_tlCNFLFLoWLWNP_vNs0P0rGYDC_9N_VS5th4-tq_zS_gV5PSo7n9RKD65_rtdpTF8NGx4kS9Bk1OeH8p6e5XE Jan 25 23:09:36 volumio volumio[15402]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 23:09:36 volumio go-librespot[15640]: time="2026-01-25T23:09:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:36 volumio volumio[15402]: info: Starting Shairport Sync Jan 25 23:09:36 volumio volumio[15402]: info: Starting Shairport Sync Jan 25 23:09:36 volumio volumio[15402]: info: Starting Shairport Sync Jan 25 23:09:36 volumio sudo[15668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 23:09:36 volumio sudo[15668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:36 volumio sudo[15671]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 23:09:36 volumio sudo[15666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 23:09:36 volumio sudo[15666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:36 volumio sudo[15671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 23:09:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 23:09:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 23:09:37 volumio systemd[1]: shairport-sync.service: Consumed 2.512s CPU time. Jan 25 23:09:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 23:09:37 volumio sudo[15668]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:37 volumio sudo[15671]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:37 volumio sudo[15666]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:37 volumio volumio[15402]: info: Shairport-Sync Started Jan 25 23:09:37 volumio volumio[15402]: Error adding Membership: Error: addMembership EINVAL Jan 25 23:09:37 volumio volumio[15402]: info: Shairport-Sync Started Jan 25 23:09:37 volumio volumio[15402]: info: Shairport-Sync Started Jan 25 23:09:37 volumio volumio[15402]: info: CoreCommandRouter::volumioGetState Jan 25 23:09:37 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:37 volumio volumio[15402]: 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 25 23:09:37 volumio volumio[15402]: info: Spotify Successfully logged in Jan 25 23:09:37 volumio volumio[15402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 23:09:37 volumio volumio[15402]: info: [1769357377625] CoreMusicLibrary::Adding element Spotify Jan 25 23:09:37 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 23:09:37 volumio volumio[15402]: Cannot find translation for source YouTube Music Jan 25 23:09:37 volumio volumio[15402]: Cannot find translation for source Spotify Jan 25 23:09:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:38 volumio volumio[15402]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 23:09:38 volumio volumio[15402]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 23:09:38 volumio volumio[15402]: info: VolumeController:: Volume=100 Mute =false Jan 25 23:09:38 volumio volumio[15402]: info: CoreCommandRouter::volumioGetState Jan 25 23:09:38 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:38 volumio volumio[15402]: info: CoreStateMachine::pushState Jan 25 23:09:38 volumio volumio[15402]: info: CorePlayQueue::getTrack 0 Jan 25 23:09:38 volumio volumio[15402]: info: CoreCommandRouter::volumioPushState Jan 25 23:09:39 volumio volumio[15402]: info: go-librespot daemon successfully initialized Jan 25 23:09:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Jan 25 23:09:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:39 volumio go-librespot[15718]: go-librespot daemon starting... Jan 25 23:09:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:39 volumio go-librespot[15719]: time="2026-01-25T23:09:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:39 volumio go-librespot[15719]: time="2026-01-25T23:09:39+07:00" level=debug msg="app state loaded" Jan 25 23:09:39 volumio go-librespot[15719]: time="2026-01-25T23:09:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:40 volumio mpd[15628]: 2026-01-25T23:09:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 23:09:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 23:09:40 volumio sudo[15579]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:40 volumio sudo[15590]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=info msg="zeroconf server listening on port 38853" Jan 25 23:09:40 volumio volumio[15402]: error: MPD error: The expression evaluated to a falsy value: Jan 25 23:09:40 volumio volumio[15402]: assert.ok(self.idling) Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="obtained new client token: AAApFDe6/lLtFU1wpl7LE9LFSPB8IZ9UUVBn+9S8kyAizAfirQ3N13T8H7kfUZphFcXIAxvVXH4od0lSDjH4uwVeVmqg1dDi10o3TuU3k7BxJdS0IRxUpd+YjrP0Clr4Y77LsraPwxr07Z+Qs1Nh519RW9qXvOT1bDlFnhXgykCeLCu3drgSa7YbE+jh2eDCaqscgu32o3d8uWje48pXhoooRy9fQ3se86yYjH6ujvbZdj9/xJ27ZXnLKYc=" Jan 25 23:09:40 volumio volumio[15402]: error: The expression evaluated to a falsy value: Jan 25 23:09:40 volumio volumio[15402]: assert.ok(self.idling) Jan 25 23:09:40 volumio volumio[15402]: info: MPD running with PID15628 Jan 25 23:09:40 volumio volumio[15402]: ,establishing connection Jan 25 23:09:40 volumio volumio[15402]: error: updateQueue error: null Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:40 volumio volumio[15402]: info: Completed starting Core Plugins Jan 25 23:09:40 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:40 volumio volumio[15402]: info: ----- MyVolumio plugins startup ---- Jan 25 23:09:40 volumio volumio[15402]: info: ------------------------------------------- Jan 25 23:09:40 volumio volumio[15402]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 23:09:40 volumio volumio[15402]: error: updateQueue error: null Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=debug msg="completed challenge" Jan 25 23:09:40 volumio go-librespot[15719]: time="2026-01-25T23:09:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:42 volumio volumio[15402]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:42 volumio volumio[15402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Jan 25 23:09:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:44 volumio go-librespot[15730]: go-librespot daemon starting... Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=debug msg="app state loaded" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=info msg="zeroconf server listening on port 46491" Jan 25 23:09:44 volumio go-librespot[15731]: time="2026-01-25T23:09:44+07:00" level=debug msg="obtained new client token: AABmaeU+8owZHUfrc7h02bJxL15W1ytAwfANVnG26NyesqeAJRO6dW9lfDS1OlDsekDYKP7ZzM2GrOcEnwUd9dMpLexbLlkJQlqUFl7Gqi0aIbkRoC1nYK4ZDKF0Q71NB7ZvSi8trg25ig1pGep0vE2dNTsxic17VhXL6oH8y6vPELG/87OXMl+oDIaIlBQLWeUkcaDXiXa8PGRxBmND2A0QqxisxT7cRVFBiij0wAPfDH0kTzK4V52NTSw=" Jan 25 23:09:45 volumio go-librespot[15731]: time="2026-01-25T23:09:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:45 volumio go-librespot[15731]: time="2026-01-25T23:09:45+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:45 volumio go-librespot[15731]: time="2026-01-25T23:09:45+07:00" level=debug msg="completed challenge" Jan 25 23:09:45 volumio go-librespot[15731]: time="2026-01-25T23:09:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:45 volumio volumio[15402]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:45 volumio volumio[15402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 23:09:45 volumio volumio[15402]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 23:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Jan 25 23:09:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:48 volumio go-librespot[15739]: go-librespot daemon starting... Jan 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+07:00" level=debug msg="app state loaded" Jan 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:48 volumio volumio[15402]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+07:00" level=debug msg="new websocket client" Jan 25 23:09:48 volumio volumio[15402]: info: Connection to go-librespot Websocket established Jan 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+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 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+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 25 23:09:48 volumio go-librespot[15740]: time="2026-01-25T23:09:48+07:00" level=info msg="zeroconf server listening on port 32955" Jan 25 23:09:49 volumio go-librespot[15740]: time="2026-01-25T23:09:49+07:00" level=debug msg="obtained new client token: AABdP5EizeqOiecUTl6xu6fEqtYPrYm0sSr2FKRrNJGOU/bv8LrxtwXOaqgObJ9k/252S3OrILknqd52Xhud2gOWUX+Zk/Y84KAGWzoUhVXUVkpzCGdmqaHDasmoyJduAXi9BNIw/VQchS+gIlHR1HG5Tff34atmFS58uUJFrdhBaC3q9b50zfqB+lPJgGyfQ2HeuVmNd3GzsoSIyHRPQYeUMNY/IP7WsqxobnFC2kxdNB20YZQYiQEq" Jan 25 23:09:49 volumio go-librespot[15740]: time="2026-01-25T23:09:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:49 volumio go-librespot[15740]: time="2026-01-25T23:09:49+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:49 volumio go-librespot[15740]: time="2026-01-25T23:09:49+07:00" level=debug msg="completed challenge" Jan 25 23:09:49 volumio go-librespot[15740]: time="2026-01-25T23:09:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:49 volumio volumio[15402]: info: Connection to go-librespot Websocket closed Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 23:09:49 volumio volumio[15402]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 23:09:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:51 volumio volumio[15402]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 23:09:51 volumio volumio[15402]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 23:09:51 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:51 volumio volumio[15402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 23:09:51 volumio volumio[15402]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 23:09:51 volumio volumio[15402]: info: MyVolumio login type: Token Jan 25 23:09:51 volumio volumio[15402]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 23:09:51 volumio volumio[15402]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 23:09:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Jan 25 23:09:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 23:09:52 volumio go-librespot[15762]: go-librespot daemon starting... Jan 25 23:09:52 volumio go-librespot[15763]: time="2026-01-25T23:09:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 23:09:52 volumio go-librespot[15763]: time="2026-01-25T23:09:52+07:00" level=debug msg="app state loaded" Jan 25 23:09:52 volumio go-librespot[15763]: time="2026-01-25T23:09:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+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 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+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 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=info msg="zeroconf server listening on port 42637" Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=debug msg="obtained new client token: AADzal7l8ag055i/PqN03li5GimAVq0sSbL8yJfDFfipV1AvGRfLe+Ibxt/aSwq6dcO0p/2Crv1430hmnkCQQnHH8KOUWXfQ449NagpyJcR1oizD65RjXarUCgbEge48/Rj2/4qpzajUHJQLv8BmrK32FgDq61GfeMeo3uTmdw9YjbOYC9qQYeRE3FEty8mHYcUXl+iqPBR+9ku3RVbeOSkXZXKdGCO2TpOMLqiyuACTcRsG8MPPeNDZoAE=" Jan 25 23:09:53 volumio volumio[15402]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 23:09:53 volumio volumio[15402]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 23:09:53 volumio volumio[15402]: info: Streaming services startup Jan 25 23:09:53 volumio volumio[15402]: info: Starting Streaming Daemon Jan 25 23:09:53 volumio sudo[15773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 23:09:53 volumio sudo[15773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 23:09:53 volumio volumio[15402]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 23:09:53 volumio sudo[15773]: pam_unix(sudo:session): session closed for user root Jan 25 23:09:53 volumio volumio[15402]: info: Getting Spotify volume Jan 25 23:09:53 volumio volumio[15402]: info: Initializing connection to go-librespot Websocket Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=debug msg="completed keyexchange" Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=debug msg="completed challenge" Jan 25 23:09:53 volumio volumio[15402]: error: Cannot start Volumio Streaming Daemon Jan 25 23:09:53 volumio volumio[15402]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 23:09:53 volumio volumio[15402]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=debug msg="new websocket client" Jan 25 23:09:53 volumio volumio[15402]: 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 25 23:09:53 volumio volumio[15402]: info: Connection to go-librespot Websocket established Jan 25 23:09:53 volumio go-librespot[15763]: time="2026-01-25T23:09:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 23:09:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 23:09:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 23:09:53 volumio volumio[15402]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 23:09:53 volumio volumio[15402]: Error: socket hang up Jan 25 23:09:53 volumio volumio[15402]: at connResetException (node:internal/errors:720:14) Jan 25 23:09:53 volumio volumio[15402]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 25 23:09:53 volumio volumio[15402]: at Socket.emit (node:events:526:35) Jan 25 23:09:53 volumio volumio[15402]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 25 23:09:53 volumio volumio[15402]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 25 23:09:53 volumio volumio[15402]: code: 'ECONNRESET', Jan 25 23:09:53 volumio volumio[15402]: response: undefined Jan 25 23:09:53 volumio volumio[15402]: } Jan 25 23:09:53 volumio volumio[15402]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 23:09:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 23:09:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 23:09:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 23:09:55 volumio sudo[15794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 23:08' Jan 25 23:09:55 volumio sudo[15794]: 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"