Jan 28 19:04:00 volumio go-librespot[30748]: time="2026-01-28T19:04:00+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:00 volumio go-librespot[30748]: time="2026-01-28T19:04:00+07:00" level=debug msg="completed challenge" Jan 28 19:04:00 volumio go-librespot[30748]: time="2026-01-28T19:04:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:00 volumio volumio[30498]: info: go-librespot daemon successfully initialized Jan 28 19:04:00 volumio mpd[30726]: 2026-01-28T19:04:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 19:04:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 19:04:00 volumio sudo[30697]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:00 volumio sudo[30686]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:01 volumio volumio[30498]: error: MPD error: The expression evaluated to a falsy value: Jan 28 19:04:01 volumio volumio[30498]: assert.ok(self.idling) Jan 28 19:04:01 volumio volumio[30498]: error: The expression evaluated to a falsy value: Jan 28 19:04:01 volumio volumio[30498]: assert.ok(self.idling) Jan 28 19:04:01 volumio volumio[30498]: error: updateQueue error: null Jan 28 19:04:01 volumio volumio[30498]: info: MPD running with PID30726 Jan 28 19:04:01 volumio volumio[30498]: ,establishing connection Jan 28 19:04:01 volumio volumio[30498]: info: Completed starting Core Plugins Jan 28 19:04:01 volumio volumio[30498]: info: ------------------------------------------- Jan 28 19:04:01 volumio volumio[30498]: info: ----- MyVolumio plugins startup ---- Jan 28 19:04:01 volumio volumio[30498]: info: ------------------------------------------- Jan 28 19:04:01 volumio volumio[30498]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 19:04:01 volumio volumio[30498]: error: updateQueue error: null Jan 28 19:04:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 19:04:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:03 volumio go-librespot[30823]: go-librespot daemon starting... Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=debug msg="app state loaded" Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:03 volumio volumio[30498]: info: Initializing connection to go-librespot Websocket Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=debug msg="new websocket client" Jan 28 19:04:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:03 volumio volumio[30498]: info: Connection to go-librespot Websocket established Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 19:04:03 volumio go-librespot[30824]: time="2026-01-28T19:04:03+07:00" level=info msg="zeroconf server listening on port 34711" Jan 28 19:04:04 volumio go-librespot[30824]: time="2026-01-28T19:04:04+07:00" level=debug msg="obtained new client token: AABBFgyg3IO62He/ox/NOdaRaIk1S8eeJdDg0zm858LTFYTkzMDhw22R3cvii3NY9uW4xi+4DzDu5VZg2cxe9FY44aZ+S90T73BMjhG7UfAUcu1uKjawhjxWoM3iV+4TjYDgxXu2fsYqcdrHXqoGDC2JlnjL5ce7THVq6DJU9F7HXbNYdGYUF0p+YvGz7bleHIVRoHalwgUX+mooGQ6GvePwA0UWaBl8BTHzJuQyZZ+gg6Jr523j4dQf" Jan 28 19:04:04 volumio go-librespot[30824]: time="2026-01-28T19:04:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:04 volumio go-librespot[30824]: time="2026-01-28T19:04:04+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:04 volumio go-librespot[30824]: time="2026-01-28T19:04:04+07:00" level=debug msg="completed challenge" Jan 28 19:04:04 volumio go-librespot[30824]: time="2026-01-28T19:04:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:04 volumio volumio[30498]: info: Connection to go-librespot Websocket closed Jan 28 19:04:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:06 volumio volumio[30498]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 19:04:06 volumio volumio[30498]: info: Getting Spotify volume Jan 28 19:04:06 volumio volumio[30498]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 19:04:06 volumio volumio[30498]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:04:06 volumio volumio[30498]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 19:04:06 volumio volumio[30498]: errno: -111, Jan 28 19:04:06 volumio volumio[30498]: code: 'ECONNREFUSED', Jan 28 19:04:06 volumio volumio[30498]: syscall: 'connect', Jan 28 19:04:06 volumio volumio[30498]: address: '127.0.0.1', Jan 28 19:04:06 volumio volumio[30498]: port: 9879, Jan 28 19:04:06 volumio volumio[30498]: response: undefined Jan 28 19:04:06 volumio volumio[30498]: } Jan 28 19:04:06 volumio volumio[30498]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 19:04:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 19:04:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:07 volumio go-librespot[30843]: go-librespot daemon starting... Jan 28 19:04:07 volumio go-librespot[30844]: time="2026-01-28T19:04:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:07 volumio go-librespot[30844]: time="2026-01-28T19:04:07+07:00" level=debug msg="app state loaded" Jan 28 19:04:07 volumio go-librespot[30844]: time="2026-01-28T19:04:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:08 volumio sudo[30853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 19:03' Jan 28 19:04:08 volumio sudo[30853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=info msg="zeroconf server listening on port 43923" Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="obtained new client token: AAD5WlUnjwQ4p73lMAZnmIm0Puu7rg6sk4JNz70DDCgsf+5qcJWvFzvVixIkKn1pTaalL/UiYUPhA6m/SBA7qG3RDCY8MKuAFP1c8oWlwG4uT9y0uEAFPr3dIQaZz2qlo1iG7p/wpVjD1wRo9tUaSAWrHBbbGu661yVxdspC2/sEJp8ax/nDTaINIXvVr7Yfyan1kVsl8BCKokfA2yUE7Zgu2mTlGC7e2Lw0g3AT+csNWI6Owu10ViV9jLc=" Jan 28 19:04:08 volumio sudo[30853]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:08 volumio volumio-remote-updater[628]: [2026-01-28 19:04:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 19:04:08 volumio volumio-remote-updater[628]: [2026-01-28 19:04:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 19:04:08 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=debug msg="completed challenge" Jan 28 19:04:08 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 19:04:08 volumio systemd[1]: volumio.service: Consumed 52.511s CPU time. Jan 28 19:04:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 19:04:08 volumio go-librespot[30844]: time="2026-01-28T19:04:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 19:04:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10537. Jan 28 19:04:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 19:04:08 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 19:04:08 volumio systemd[1]: volumio.service: Consumed 52.511s CPU time. Jan 28 19:04:08 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 19:04:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 19:04:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 19:04:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:11 volumio go-librespot[30884]: go-librespot daemon starting... Jan 28 19:04:11 volumio go-librespot[30885]: time="2026-01-28T19:04:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:11 volumio go-librespot[30885]: time="2026-01-28T19:04:11+07:00" level=debug msg="app state loaded" Jan 28 19:04:11 volumio go-librespot[30885]: time="2026-01-28T19:04:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=info msg="zeroconf server listening on port 42603" Jan 28 19:04:12 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:12 volumio volumio[30867]: info: ----- Volumio3 ---- Jan 28 19:04:12 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:12 volumio volumio[30867]: info: ----- System startup ---- Jan 28 19:04:12 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="obtained new client token: AADZJRztjEdOjDbjEteN2hWNsG8UyEf2/6Zmydg71yGu4fFWuiudcxEwUfhRRMuUBe7+tq7aGl+LQn0G0gETVbg5KC4YMpPh0xheeGaLhO8tlNFWLtbWqn1h2j0EWb2K1n30D1ZEpQoTCnbRdQLvghieaR52fjivAtc7I0QXe0e9/l0VSPfpp8945X5cU7Gpix3zktmQ1yOIrXiqT6BS6FELa34gsyUljG5zrgI5rgY+oGli98plz68HKcg=" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=debug msg="completed challenge" Jan 28 19:04:12 volumio go-librespot[30885]: time="2026-01-28T19:04:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:13 volumio volumio-remote-updater[628]: [2026-01-28 19:04:13] [connect] Successful connection Jan 28 19:04:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:13 volumio volumio[30867]: info: MYVOLUMIO Environment detected Jan 28 19:04:13 volumio volumio[30867]: info: Plugin folders cleanup Jan 28 19:04:13 volumio volumio[30867]: info: Scanning into folder /volumio/app/plugins/ Jan 28 19:04:13 volumio volumio[30867]: info: Scanning category audio_interface Jan 28 19:04:13 volumio volumio[30867]: info: Scanning category miscellanea Jan 28 19:04:14 volumio volumio[30867]: info: Scanning category music_service Jan 28 19:04:14 volumio volumio[30867]: info: Scanning category plugins.json Jan 28 19:04:14 volumio volumio[30867]: info: Scanning category system_controller Jan 28 19:04:14 volumio volumio[30867]: info: Scanning category user_interface Jan 28 19:04:14 volumio volumio[30867]: info: Scanning into folder /data/plugins/ Jan 28 19:04:14 volumio volumio[30867]: info: Scanning category music_service Jan 28 19:04:14 volumio volumio[30867]: info: Plugin folders cleanup completed Jan 28 19:04:14 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:14 volumio volumio[30867]: info: ----- Core plugins startup ---- Jan 28 19:04:14 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:14 volumio volumio[30867]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 19:04:14 volumio volumio[30867]: info: Adding plugin upnp to MyMusic Plugins Jan 28 19:04:14 volumio volumio[30867]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 19:04:14 volumio volumio[30867]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 19:04:14 volumio volumio[30867]: info: Loading plugins from folder /data/plugins/ Jan 28 19:04:14 volumio volumio[30867]: info: Loading plugin "system"... Jan 28 19:04:14 volumio volumio[30867]: info: Loading plugin "appearance"... Jan 28 19:04:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:15 volumio volumio[30867]: info: Loading plugin "network"... Jan 28 19:04:16 volumio volumio[30867]: info: Refreshing Cached IP Addresses Jan 28 19:04:16 volumio sudo[30905]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 19:04:16 volumio sudo[30905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:16 volumio sudo[30907]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "services"... Jan 28 19:04:16 volumio sudo[30907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:16 volumio sudo[30905]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "alsa_controller"... Jan 28 19:04:16 volumio sudo[30907]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:16 volumio sudo[30914]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 19:04:16 volumio sudo[30914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 19:04:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:16 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "wizard"... Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "networkfs"... Jan 28 19:04:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:16 volumio go-librespot[30938]: go-librespot daemon starting... Jan 28 19:04:16 volumio volumio[30867]: info: Starting Udev Watcher for removable devices Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=debug msg="app state loaded" Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:16 volumio volumio[30867]: info: Ignoring mount for partition: boot Jan 28 19:04:16 volumio volumio[30867]: info: Ignoring mount for partition: volumio Jan 28 19:04:16 volumio volumio[30867]: info: Ignoring mount for partition: volumio_data Jan 28 19:04:16 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "volumio_command_line_client"... Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "upnp"... Jan 28 19:04:16 volumio volumio[30867]: info: [1769601856435] Starting Upmpd Daemon Jan 28 19:04:16 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "my_music"... Jan 28 19:04:16 volumio volumio[30867]: info: Loading plugin "mpd"... Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:16 volumio go-librespot[30939]: time="2026-01-28T19:04:16+07:00" level=info msg="zeroconf server listening on port 45337" Jan 28 19:04:17 volumio volumio[30867]: info: Loading plugin "upnp_browser"... Jan 28 19:04:17 volumio go-librespot[30939]: time="2026-01-28T19:04:17+07:00" level=debug msg="obtained new client token: AAB8J0wJke3ikmAwXIq5fNszz09yPiuSjWdsyVAgdKNbOnuIepWqP3Vmju1f6VRJs1ukAHT6n/EfPaqMBBHMxQmDmoTzXUr7O7/V5NS8e3x2mjkbavl36VEngy3IQhtiRDv1GqWQx57lVpEeJWrj3+DiV0GSgfVt3dhdus8SASbSKXfYfYLEE1IModlBOIymj8i3cohVag3Wl9AfP+2dNBlvEtMNGfxYvqf36N/R3IOfP2mde3Ph8lT0" Jan 28 19:04:17 volumio go-librespot[30939]: time="2026-01-28T19:04:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:17 volumio go-librespot[30939]: time="2026-01-28T19:04:17+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:17 volumio go-librespot[30939]: time="2026-01-28T19:04:17+07:00" level=debug msg="completed challenge" Jan 28 19:04:17 volumio go-librespot[30939]: time="2026-01-28T19:04:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:18 volumio sudo[30914]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:20 volumio volumio[30867]: info: Starting UPNP Browser Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "alarm-clock"... Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "airplay_emulation"... Jan 28 19:04:20 volumio volumio[30867]: info: Starting Shairport Sync Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "last_100"... Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "webradio"... Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "i2s_dacs"... Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "volumiodiscovery"... Jan 28 19:04:20 volumio volumio[30867]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 19:04:20 volumio volumio[30867]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:04:20 volumio node[30867]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 19:04:20 volumio volumio[30867]: *** WARNING *** For more information see Jan 28 19:04:20 volumio volumio[30867]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 19:04:20 volumio volumio[30867]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:04:20 volumio volumio[30867]: *** WARNING *** For more information see Jan 28 19:04:20 volumio node[30867]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:04:20 volumio node[30867]: *** WARNING *** For more information see Jan 28 19:04:20 volumio node[30867]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 19:04:20 volumio node[30867]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:04:20 volumio node[30867]: *** WARNING *** For more information see Jan 28 19:04:20 volumio volumio[30867]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 19:04:20 volumio volumio[30867]: info: Discovery: Started advertising with name: Volumio Jan 28 19:04:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 19:04:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:20 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 19:04:20 volumio volumio[30867]: info: Loading plugin "spop"... Jan 28 19:04:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:20 volumio go-librespot[30949]: go-librespot daemon starting... Jan 28 19:04:20 volumio go-librespot[30950]: time="2026-01-28T19:04:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:20 volumio go-librespot[30950]: time="2026-01-28T19:04:20+07:00" level=debug msg="app state loaded" Jan 28 19:04:20 volumio go-librespot[30950]: time="2026-01-28T19:04:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=info msg="zeroconf server listening on port 33541" Jan 28 19:04:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="obtained new client token: AACl97bL13vr1vNR16OgSij/mKBsMFe49hx1T8S9CGmqlY4m5ZMYT9zp84KtpVRXK8ojFaTFzwIpZtALqizT+V0itJRF14b+4qOKxJMLwDUCdvINoQ2hV1ZeoICzFHgnKzOcb6RWA2T53k3HXu/O4wwJgnjSpdqhJJ8PbnFh7CUDNYrxMxGxs2iEhWVjeOuzmfIptxIpiJJQpvbC5jvhSxJwUh6j2zmPTFmDLsIIcuftZBNh6z56xsZVNTU=" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:21 volumio go-librespot[30950]: time="2026-01-28T19:04:21+07:00" level=debug msg="completed challenge" Jan 28 19:04:22 volumio go-librespot[30950]: time="2026-01-28T19:04:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:22 volumio volumio[30867]: info: Loading plugin "ytcr"... Jan 28 19:04:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 19:04:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:25 volumio volumio[30867]: info: Loading plugin "ytmusic"... Jan 28 19:04:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:25 volumio go-librespot[30958]: go-librespot daemon starting... Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=debug msg="app state loaded" Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:25 volumio go-librespot[30959]: time="2026-01-28T19:04:25+07:00" level=info msg="zeroconf server listening on port 33867" Jan 28 19:04:26 volumio volumio-remote-updater[628]: [2026-01-28 19:04:26] [connect] Successful connection Jan 28 19:04:26 volumio go-librespot[30959]: time="2026-01-28T19:04:26+07:00" level=debug msg="obtained new client token: AABnfyxMelHfVRZs/kpiNJf2RWVcmrtT99AX8btb3YlbYQfbaOoJg1wCPvWNLc60d16EhfVXRSBKZYBWARIkB355JryfdAQCnapfCkfRJvmIhd1Q5eatlVFUBsNAZO9QTFu9HOz4W0PW+awkuVQOE5fJ8+EIDEUznUAVAlCikTj51LNvSYtOOlTuFuFTnqqdEBXvW03vSBNhkywnLWwoelXYHSNgQXeSjvTGkykpeXvs1bb/9A0oMHgd" Jan 28 19:04:26 volumio go-librespot[30959]: time="2026-01-28T19:04:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:26 volumio go-librespot[30959]: time="2026-01-28T19:04:26+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:26 volumio go-librespot[30959]: time="2026-01-28T19:04:26+07:00" level=debug msg="completed challenge" Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "outputs"... Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "albumart"... Jan 28 19:04:26 volumio go-librespot[30959]: time="2026-01-28T19:04:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:26 volumio volumio[30867]: info: Plugin example_plugin is not enabled Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "inputs"... Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "updater_comm"... Jan 28 19:04:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:26 volumio volumio[30867]: info: Plugin mpdemulation is not enabled Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "rest_api"... Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "websocket"... Jan 28 19:04:26 volumio volumio[30867]: info: Starting Socket.io Server version 1.7.4 Jan 28 19:04:26 volumio volumio[30867]: info: Loading plugin "RoonBridge"... Jan 28 19:04:27 volumio volumio[30867]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 19:04:27 volumio volumio[30867]: info: Loading i18n strings for locale en Jan 28 19:04:27 volumio volumio[30867]: Updating browse sources language Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:04:27 volumio volumio[30982]: Forking 3 albumart workers Jan 28 19:04:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::initPlayerControls Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 19:04:27 volumio volumio[30867]: Express server listening on port 3000 Jan 28 19:04:27 volumio volumio[30867]: [Metrics] WebUI: 16s 177.27ms Jan 28 19:04:27 volumio volumio[30867]: info: CoreStateMachine::resetVolumioState Jan 28 19:04:27 volumio volumio[30867]: info: CoreStateMachine::getcurrentVolume Jan 28 19:04:27 volumio volumio[30867]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 19:04:27 volumio sudo[31027]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 19:04:27 volumio sudo[31027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:27 volumio volumio[30867]: info: Volumio Network Manager: Network status updated: 1 Jan 28 19:04:27 volumio sudo[31027]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:27 volumio sudo[31029]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 19:04:27 volumio sudo[31029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:27 volumio sudo[31029]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:28 volumio volumio[30867]: info: VolumeController:: Volume=100 Mute =false Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::pushState Jan 28 19:04:28 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::volumioPushState Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::updateTrackBlock Jan 28 19:04:28 volumio volumio[30867]: info: CorePlayQueue::getTrackBlock Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 19:04:28 volumio volumio-remote-updater[628]: [2026-01-28 19:04:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769601866 101 Jan 28 19:04:28 volumio volumio[30867]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:28 volumio volumio[30867]: info: Reloading queue from file Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::setRepeat null single undefined Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::pushState Jan 28 19:04:28 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::volumioPushState Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::setRandom null Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::pushState Jan 28 19:04:28 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::volumioPushState Jan 28 19:04:28 volumio volumio[30867]: info: Setting Device type: Raspberry PI Jan 28 19:04:28 volumio volumio[30867]: info: Completed loading Core Plugins Jan 28 19:04:28 volumio volumio[30867]: info: Preparing to generate the ALSA configuration file Jan 28 19:04:28 volumio volumio[30867]: info: VolumeController:: Volume=100 Mute =false Jan 28 19:04:28 volumio volumio[30867]: info: CoreStateMachine::pushState Jan 28 19:04:28 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::volumioPushState Jan 28 19:04:28 volumio volumio[30867]: info: Asound.conf file unchanged, so no further update is needed Jan 28 19:04:28 volumio volumio[30867]: info: Output device has changed, restarting MPD Jan 28 19:04:28 volumio volumio[30867]: info: Output device has changed, restarting Shairport Sync Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:28 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:28 volumio sudo[31043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 19:04:28 volumio sudo[31043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:28 volumio sudo[31045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 19:04:28 volumio sudo[31045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:28 volumio sudo[31045]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:28 volumio sudo[31047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 19:04:28 volumio sudo[31047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:28 volumio volumio[30867]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 19:04:28 volumio volumio[30867]: info: ___________ START PLUGINS ___________ Jan 28 19:04:28 volumio volumio[30867]: info: ControllerMpd::onStart: Initializing MPD Jan 28 19:04:28 volumio volumio[30867]: info: Creating MPD Configuration file Jan 28 19:04:29 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 19:04:29 volumio sudo[31043]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:29 volumio sudo[31056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 19:04:29 volumio sudo[31056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:04:29 volumio sudo[31056]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:29 volumio volumio[30867]: info: [1769601869111] CoreMusicLibrary::Adding element Media Servers Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:04:29 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 19:04:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 19:04:29 volumio systemd[1]: mpd.service: Consumed 7.210s CPU time. Jan 28 19:04:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 19:04:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 19:04:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 19:04:29 volumio volumio[30867]: info: UPNP Browser: Client initialized successfully Jan 28 19:04:29 volumio sudo[31058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 19:04:29 volumio sudo[31058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 19:04:29 volumio volumio[30867]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 19:04:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:29 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 19:04:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 19:04:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 19:04:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 19:04:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 19:04:29 volumio volumio[30867]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 19:04:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:04:29 volumio volumio[30867]: info: [1769601869414] CoreMusicLibrary::Adding element Last_100 Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:04:29 volumio volumio[30867]: info: [1769601869435] CoreMusicLibrary::Adding element Webradio Jan 28 19:04:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 19:04:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 19:04:29 volumio volumio[30867]: info: Initializing BBC Radios Jan 28 19:04:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:29 volumio go-librespot[31074]: go-librespot daemon starting... Jan 28 19:04:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:29 volumio go-librespot[31077]: time="2026-01-28T19:04:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:29 volumio go-librespot[31077]: time="2026-01-28T19:04:29+07:00" level=debug msg="app state loaded" Jan 28 19:04:29 volumio go-librespot[31077]: time="2026-01-28T19:04:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:29 volumio volumio[30867]: info: Creating Spotify config file Jan 28 19:04:29 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:29 volumio sudo[31072]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 19:04:29 volumio sudo[31072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 19:04:29 volumio sudo[31072]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=info msg="zeroconf server listening on port 35673" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="obtained new client token: AABlx8isEbNNsng4+9uQDl4EZgfu9ZomH6V87McU2srD0/Get0KOWeGT+L8wImsZkA9pWreEj3mGQnb5iZGLFIn66IugG0r7XLt4NHppKuY2tPt/Y53uJ+aMG++Z1TFtS3wWyJIn6Ybes8tBNa/vbTZmU18M2y+fYXecZSYfa6gDMhBMSiKiuxgiFya+G0zJNkNDcQNLyWCSD4GDD0yrGMUGfcgx0fk8yBvUa94XAUHpHkK5w8zwjdzQPeg=" Jan 28 19:04:30 volumio volumio[30992]: Starting albumart workers Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=debug msg="completed challenge" Jan 28 19:04:30 volumio go-librespot[31077]: time="2026-01-28T19:04:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:30 volumio volumio[30993]: Starting albumart workers Jan 28 19:04:31 volumio volumio[30867]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:04:31 volumio volumio[30867]: info: [1769601871418] CoreMusicLibrary::Adding element YouTube Music Jan 28 19:04:31 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:04:31 volumio volumio[30867]: Cannot find translation for source YouTube Music Jan 28 19:04:31 volumio volumio[30867]: info: Volumio Calling Home Jan 28 19:04:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:31 volumio sudo[31098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 19:04:31 volumio sudo[31098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:31 volumio volumio[30994]: Starting albumart workers Jan 28 19:04:31 volumio sudo[31098]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:32 volumio volumio[30867]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 19:04:32 volumio volumio[30867]: info: Discovery: Found device Volumio Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::volumioGetState Jan 28 19:04:32 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:32 volumio volumio[30867]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 19:04:32 volumio volumio[30867]: info: Discovery: Found device Volumio Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::volumioGetState Jan 28 19:04:32 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:32 volumio volumio[30867]: info: MPD Permissions set Jan 28 19:04:32 volumio volumio[30867]: info: MPD Permissions set Jan 28 19:04:32 volumio volumio[30867]: info: Upmpdcli Daemon Started Jan 28 19:04:32 volumio volumio[30867]: info: Spotify config file written Jan 28 19:04:32 volumio volumio[30867]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 19:04:32 volumio volumio[30867]: info: Volumio called home Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio sudo[31110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio sudo[31110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:04:32 volumio volumio[30867]: info: No need to fix Spotify hosts Jan 28 19:04:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:32 volumio go-librespot[31127]: go-librespot daemon starting... Jan 28 19:04:32 volumio sudo[31110]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:32 volumio go-librespot[31129]: time="2026-01-28T19:04:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:32 volumio go-librespot[31129]: time="2026-01-28T19:04:32+07:00" level=debug msg="app state loaded" Jan 28 19:04:32 volumio go-librespot[31129]: time="2026-01-28T19:04:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=info msg="zeroconf server listening on port 34501" Jan 28 19:04:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:33 volumio volumio[30867]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 19:04:33 volumio volumio[30867]: SPOTIFY: BQBal4YVa_OarkNLB2Kg_11OtlyBrBqMYQkwWN7fu64veDRJrBAHoMJXwBBSby-E-pRpQlMi735eArDi21W8ojnbPVxQV1mpQmaVHdQvDw462G5ye--tFSmtR_OFrNaAqJi9GqXJXolNf_p0l2Rso2l641M6WZDjJHZJYa1GBF1g4D24YKGYQ4BzXb3FQZCYk1tPFvGReF-NHtli4MFt57zk-PaNEhy8agMm79aXoAn3kNr-XUqwk0WDU84pRddDXMGrluQ17Dc_cBPwjSDOj-9Sr7vdb8iADeEhWV7KwGYCsF14zoHMBOEB Jan 28 19:04:33 volumio volumio[30867]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 19:04:33 volumio volumio[30867]: info: New Spotify access token = BQBal4YVa_OarkNLB2Kg_11OtlyBrBqMYQkwWN7fu64veDRJrBAHoMJXwBBSby-E-pRpQlMi735eArDi21W8ojnbPVxQV1mpQmaVHdQvDw462G5ye--tFSmtR_OFrNaAqJi9GqXJXolNf_p0l2Rso2l641M6WZDjJHZJYa1GBF1g4D24YKGYQ4BzXb3FQZCYk1tPFvGReF-NHtli4MFt57zk-PaNEhy8agMm79aXoAn3kNr-XUqwk0WDU84pRddDXMGrluQ17Dc_cBPwjSDOj-9Sr7vdb8iADeEhWV7KwGYCsF14zoHMBOEB Jan 28 19:04:33 volumio volumio[30867]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="obtained new client token: AAD4AQc0/xEdZ1CH1gWsUV0APdQCCyuJFITCEbEYllnVF7CZRowjvJ2C9jMMneGp2r37HydCf2A9gyc52YVIaW9tsyHw574RTd/y8HOiJxb/Acza4KRPEJJbEDWTVSHbROkYtrWeD3dgRxffrhvH6UFpFPrI1GspgQ+uCaBdDQNTvjM4NzlJ4419gPzVK96/43KeK2uBWgqQyEseqFSD+PBmr5/4ysoHXleDWHar2HjQwAbIUmWmLH/8rvk=" Jan 28 19:04:33 volumio volumio[30867]: info: Starting Shairport Sync Jan 28 19:04:33 volumio volumio[30867]: info: Starting Shairport Sync Jan 28 19:04:33 volumio volumio[30867]: info: Starting Shairport Sync Jan 28 19:04:33 volumio sudo[31144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:33 volumio sudo[31144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:33 volumio sudo[31146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 19:04:33 volumio sudo[31146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:33 volumio sudo[31148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 19:04:33 volumio sudo[31148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:33 volumio go-librespot[31129]: time="2026-01-28T19:04:33+07:00" level=debug msg="completed challenge" Jan 28 19:04:34 volumio go-librespot[31129]: time="2026-01-28T19:04:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 19:04:34 volumio volumio[30867]: info: CoreCommandRouter::volumioGetState Jan 28 19:04:34 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 19:04:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 19:04:34 volumio systemd[1]: shairport-sync.service: Consumed 2.208s CPU time. Jan 28 19:04:34 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 19:04:34 volumio sudo[31148]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:34 volumio sudo[31146]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:34 volumio sudo[31144]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:34 volumio volumio[30867]: info: Shairport-Sync Started Jan 28 19:04:34 volumio volumio[30867]: Error adding Membership: Error: addMembership EINVAL Jan 28 19:04:34 volumio volumio[30867]: info: Shairport-Sync Started Jan 28 19:04:34 volumio volumio[30867]: info: Shairport-Sync Started Jan 28 19:04:34 volumio volumio[30867]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 19:04:34 volumio volumio[30867]: info: Spotify Successfully logged in Jan 28 19:04:34 volumio volumio[30867]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:04:34 volumio volumio[30867]: info: [1769601874614] CoreMusicLibrary::Adding element Spotify Jan 28 19:04:34 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:04:34 volumio volumio[30867]: Cannot find translation for source YouTube Music Jan 28 19:04:34 volumio volumio[30867]: Cannot find translation for source Spotify Jan 28 19:04:35 volumio volumio[30867]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 19:04:35 volumio volumio[30867]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 19:04:35 volumio volumio[30867]: info: VolumeController:: Volume=100 Mute =false Jan 28 19:04:35 volumio volumio[30867]: info: CoreCommandRouter::volumioGetState Jan 28 19:04:35 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:35 volumio volumio[30867]: info: CoreStateMachine::pushState Jan 28 19:04:35 volumio volumio[30867]: info: CorePlayQueue::getTrack 0 Jan 28 19:04:35 volumio volumio[30867]: info: CoreCommandRouter::volumioPushState Jan 28 19:04:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:36 volumio volumio[30867]: info: go-librespot daemon successfully initialized Jan 28 19:04:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 19:04:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:37 volumio mpd[31094]: 2026-01-28T19:04:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 19:04:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:37 volumio go-librespot[31185]: go-librespot daemon starting... Jan 28 19:04:37 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 19:04:37 volumio sudo[31047]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:37 volumio sudo[31058]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=debug msg="app state loaded" Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:37 volumio volumio[30867]: error: MPD error: The expression evaluated to a falsy value: Jan 28 19:04:37 volumio volumio[30867]: assert.ok(self.idling) Jan 28 19:04:37 volumio volumio[30867]: error: The expression evaluated to a falsy value: Jan 28 19:04:37 volumio volumio[30867]: assert.ok(self.idling) Jan 28 19:04:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:37 volumio volumio[30867]: info: MPD running with PID31094 Jan 28 19:04:37 volumio volumio[30867]: ,establishing connection Jan 28 19:04:37 volumio volumio[30867]: error: updateQueue error: null Jan 28 19:04:37 volumio volumio[30867]: info: Completed starting Core Plugins Jan 28 19:04:37 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:37 volumio volumio[30867]: info: ----- MyVolumio plugins startup ---- Jan 28 19:04:37 volumio volumio[30867]: info: ------------------------------------------- Jan 28 19:04:37 volumio volumio[30867]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 19:04:37 volumio volumio[30867]: error: updateQueue error: null Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:37 volumio go-librespot[31188]: time="2026-01-28T19:04:37+07:00" level=info msg="zeroconf server listening on port 39905" Jan 28 19:04:38 volumio go-librespot[31188]: time="2026-01-28T19:04:38+07:00" level=debug msg="obtained new client token: AAApdhsMHftyteAXK5WezTxgTHkv02W4I+5aMRSHs0eREvWesAdqUnCSEYyrBSGmp80tsBuAxNqga9tIE3LhkOOx2vFgaezea51JF1oj3cKML2H+x+o0Tl5JujoFkdBSppHOT4rHAl7Ca9LEDvmIBJLKJKsNeYzaDpyHTiiM+ucRqukZGwKX/6Gu3d/tz5LfOZ9vxKH6DuRsglQ4DZRdXDaAM+i0k5uDuA4PZTD+yopwFe3rbyp8MypZ" Jan 28 19:04:38 volumio go-librespot[31188]: time="2026-01-28T19:04:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:38 volumio go-librespot[31188]: time="2026-01-28T19:04:38+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:38 volumio go-librespot[31188]: time="2026-01-28T19:04:38+07:00" level=debug msg="completed challenge" Jan 28 19:04:38 volumio go-librespot[31188]: time="2026-01-28T19:04:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:39 volumio volumio[30867]: info: Initializing connection to go-librespot Websocket Jan 28 19:04:39 volumio volumio[30867]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:04:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 19:04:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:41 volumio go-librespot[31198]: go-librespot daemon starting... Jan 28 19:04:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:41 volumio go-librespot[31199]: time="2026-01-28T19:04:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:41 volumio go-librespot[31199]: time="2026-01-28T19:04:41+07:00" level=debug msg="app state loaded" Jan 28 19:04:41 volumio go-librespot[31199]: time="2026-01-28T19:04:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=info msg="zeroconf server listening on port 42417" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="obtained new client token: AABrccw9Csbo4Avy4DTn1HhHuF33kvodhoafo9PgTtCiPwzQm1B/s2K8KYZQLRcYYBfSfum+NlYo7XY26gIAiCFt9UPPp0VfuFv7g4x5vKPAsPeY9fFyeoX6QvCbhhVdsuUB5WdZSAugy0ODjP2nsER/DgziZKbiqpZFcnHWCtbSA3FiQ+ld9bhgRv82cnL4oTOfUYj+BL5sFSpVwa085yPNqIdKWgUjkDrLKIx4YrnVD6EUZSRQtRc0h5g=" Jan 28 19:04:42 volumio volumio[30867]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=debug msg="completed challenge" Jan 28 19:04:42 volumio go-librespot[31199]: time="2026-01-28T19:04:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:42 volumio volumio[30867]: info: Initializing connection to go-librespot Websocket Jan 28 19:04:42 volumio volumio[30867]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:04:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 19:04:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:45 volumio volumio[30867]: info: Initializing connection to go-librespot Websocket Jan 28 19:04:45 volumio volumio[30867]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:04:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:45 volumio go-librespot[31209]: go-librespot daemon starting... Jan 28 19:04:45 volumio go-librespot[31210]: time="2026-01-28T19:04:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:45 volumio go-librespot[31210]: time="2026-01-28T19:04:45+07:00" level=debug msg="app state loaded" Jan 28 19:04:45 volumio go-librespot[31210]: time="2026-01-28T19:04:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=info msg="zeroconf server listening on port 34985" Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 19:04:46 volumio volumio[30867]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="obtained new client token: AADWmGFjMNY8Q0bzLHGoqrQVls/d0YuPZ5g4y4AFRTTHuJONJKGx42ZWwaMw4OXoxXU+twEkPfTvIXj6hYr1e1yMjDdmBV58c2Ym65UsVfNkqQjCjuJHEHtXX8yTWH8LTWi1UuRoSYIngrEqBbpy0/ncGlwaf9beeayyMd/DE3vAR/vbJyK2UobBT7lWAWC/wl2ZzZ9O9vGI85rJRPuMLu5JZ5STK0bGV8//2hN/qldn3FrThtbPyADvXS8=" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=debug msg="completed challenge" Jan 28 19:04:46 volumio go-librespot[31210]: time="2026-01-28T19:04:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:48 volumio volumio[30867]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 19:04:48 volumio volumio[30867]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 19:04:48 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:48 volumio volumio[30867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:04:48 volumio volumio[30867]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 19:04:48 volumio volumio[30867]: info: MyVolumio login type: Token Jan 28 19:04:48 volumio volumio[30867]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 19:04:48 volumio volumio[30867]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 19:04:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 19:04:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:50 volumio go-librespot[31232]: go-librespot daemon starting... Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=debug msg="app state loaded" Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:50 volumio volumio[30867]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 19:04:50 volumio volumio[30867]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 19:04:50 volumio volumio[30867]: info: Streaming services startup Jan 28 19:04:50 volumio volumio[30867]: info: Starting Streaming Daemon Jan 28 19:04:50 volumio volumio[30867]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 19:04:50 volumio sudo[31240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 19:04:50 volumio sudo[31240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:50 volumio sudo[31240]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:50 volumio volumio[30867]: info: Initializing connection to go-librespot Websocket Jan 28 19:04:50 volumio volumio[30867]: error: Cannot start Volumio Streaming Daemon Jan 28 19:04:50 volumio volumio[30867]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 19:04:50 volumio volumio[30867]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=debug msg="new websocket client" Jan 28 19:04:50 volumio volumio[30867]: info: Connection to go-librespot Websocket established Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=info msg="zeroconf server listening on port 36381" Jan 28 19:04:50 volumio go-librespot[31233]: time="2026-01-28T19:04:50+07:00" level=debug msg="obtained new client token: AACtd/QFX8cpdbhybqc/AO0ucoysoWjMTAaOhqgbhNCFoM6ZyPitO4g3XG8OzjCAAYUCRIxwla5XBUI2RB77d01LYvs8He+Q9ZeY9cR/ygeQig/m0uAvJu45+7qqWIgbnEi4BkFZiqU3rYPt9nTfM2k8q6jVwKwDbH928voz9zDcL0KLTUOtk1nZ8NQQEbID5WW0zNplIjeout8SV9JMdcur52rmHPr0t4QAg10Wx4dPDunYPqkJxFph+Y8=" Jan 28 19:04:51 volumio go-librespot[31233]: time="2026-01-28T19:04:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:51 volumio go-librespot[31233]: time="2026-01-28T19:04:51+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:51 volumio go-librespot[31233]: time="2026-01-28T19:04:51+07:00" level=debug msg="completed challenge" Jan 28 19:04:51 volumio go-librespot[31233]: time="2026-01-28T19:04:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:51 volumio volumio[30867]: info: Connection to go-librespot Websocket closed Jan 28 19:04:51 volumio volumio[30867]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 19:04:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:52 volumio volumio[30867]: info: MyVolumio token set successfully Jan 28 19:04:52 volumio volumio[30867]: info: MYVOLUMIO: Adding device Jan 28 19:04:52 volumio volumio[30867]: info: MYVOLUMIO: Evaluating Server Jan 28 19:04:53 volumio volumio[30867]: info: MyVolumio status changed Jan 28 19:04:53 volumio volumio[30867]: info: Streaming services startup Jan 28 19:04:53 volumio volumio[30867]: info: Starting Streaming Daemon Jan 28 19:04:53 volumio volumio[30867]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 19:04:53 volumio volumio[30867]: info: Removing audio output: Jan 28 19:04:53 volumio volumio[30867]: info: Stoppping Tunnel 1 Jan 28 19:04:53 volumio sudo[31268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 19:04:53 volumio sudo[31268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:53 volumio sudo[31268]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:53 volumio volumio[30867]: error: Cannot start Volumio Streaming Daemon Jan 28 19:04:53 volumio volumio[30867]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 19:04:53 volumio volumio[30867]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 19:04:53 volumio sudo[31271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 19:04:53 volumio sudo[31271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 19:04:53 volumio sudo[31271]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:53 volumio volumio[30867]: info: Remote SSH Stopped Jan 28 19:04:53 volumio volumio[30867]: info: Getting Spotify volume Jan 28 19:04:53 volumio volumio[30867]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 19:04:53 volumio volumio[30867]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:04:53 volumio volumio[30867]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 19:04:53 volumio volumio[30867]: errno: -111, Jan 28 19:04:53 volumio volumio[30867]: code: 'ECONNREFUSED', Jan 28 19:04:53 volumio volumio[30867]: syscall: 'connect', Jan 28 19:04:53 volumio volumio[30867]: address: '127.0.0.1', Jan 28 19:04:53 volumio volumio[30867]: port: 9879, Jan 28 19:04:53 volumio volumio[30867]: response: undefined Jan 28 19:04:53 volumio volumio[30867]: } Jan 28 19:04:53 volumio volumio[30867]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 19:04:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 19:04:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:54 volumio go-librespot[31285]: go-librespot daemon starting... Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=debug msg="app state loaded" Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:54 volumio go-librespot[31286]: time="2026-01-28T19:04:54+07:00" level=info msg="zeroconf server listening on port 37087" Jan 28 19:04:54 volumio sudo[31295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 19:03' Jan 28 19:04:54 volumio sudo[31295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:04:55 volumio go-librespot[31286]: time="2026-01-28T19:04:55+07:00" level=debug msg="obtained new client token: AAB69BYL739apYine6giqUcuju5WKBpWT5pcSkLCBg8799RuSeNCMJjES0M5jD7lvfN0RFrztPADPpVLNWGiwYVf78Ad1OfAfvak7dFPvKw7Aewxp/ubFmq1o/3/CFsmPG+y5SrJYbw2QV0i2CgexozM89NMpKHB0Y1Mr/WTu6OJRP/9gFjkFrkOiBvE2gniR6NPskdbm7zJZsdKRhvDRFtL5MHBc5K9h33IKsClNunXAaJ+ydNFXUjw" Jan 28 19:04:55 volumio go-librespot[31286]: time="2026-01-28T19:04:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:55 volumio go-librespot[31286]: time="2026-01-28T19:04:55+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:55 volumio go-librespot[31286]: time="2026-01-28T19:04:55+07:00" level=debug msg="completed challenge" Jan 28 19:04:55 volumio sudo[31295]: pam_unix(sudo:session): session closed for user root Jan 28 19:04:55 volumio go-librespot[31286]: time="2026-01-28T19:04:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:55 volumio volumio-remote-updater[628]: [2026-01-28 19:04:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 19:04:55 volumio volumio-remote-updater[628]: [2026-01-28 19:04:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 19:04:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 19:04:55 volumio systemd[1]: volumio.service: Consumed 1min 311ms CPU time. Jan 28 19:04:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 19:04:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 19:04:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10538. Jan 28 19:04:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 19:04:56 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 19:04:56 volumio systemd[1]: volumio.service: Consumed 1min 311ms CPU time. Jan 28 19:04:56 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 19:04:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 19:04:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 19:04:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:04:58 volumio go-librespot[31325]: go-librespot daemon starting... Jan 28 19:04:58 volumio go-librespot[31326]: time="2026-01-28T19:04:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:04:58 volumio go-librespot[31326]: time="2026-01-28T19:04:58+07:00" level=debug msg="app state loaded" Jan 28 19:04:58 volumio go-librespot[31326]: time="2026-01-28T19:04:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=info msg="zeroconf server listening on port 44499" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="obtained new client token: AACprFibhnZUduJxTBvi2t7YAwGY9j/z/CBds/7CBVGod1uRFq0d1J8hZThccNUKPA89pc6I3Q/L8CHP3v0akUfd30xIYhsrUyRKZCp+MRBqLl92jouHBRGNWNh5egDqHYl7NWdA+EC00/UwCP3GXH28JEwoPXLzJxsHR3zsFMOLEQmyPNS/jx67fFjJ23+vkwIcfm2rZwFAsdaJQfqKwqwL+5iTcO91sV0UUh2xCS5duKrqShc0HnOZZbo=" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:04:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:04:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:04:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="completed keyexchange" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=debug msg="completed challenge" Jan 28 19:04:59 volumio go-librespot[31326]: time="2026-01-28T19:04:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:04:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:04:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:04:59 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:04:59 volumio volumio[31310]: info: ----- Volumio3 ---- Jan 28 19:04:59 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:04:59 volumio volumio[31310]: info: ----- System startup ---- Jan 28 19:04:59 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:05:00 volumio volumio-remote-updater[628]: [2026-01-28 19:05:00] [connect] Successful connection Jan 28 19:05:01 volumio volumio[31310]: info: MYVOLUMIO Environment detected Jan 28 19:05:01 volumio volumio[31310]: info: Plugin folders cleanup Jan 28 19:05:01 volumio volumio[31310]: info: Scanning into folder /volumio/app/plugins/ Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category audio_interface Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category miscellanea Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category music_service Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category plugins.json Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category system_controller Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category user_interface Jan 28 19:05:01 volumio volumio[31310]: info: Scanning into folder /data/plugins/ Jan 28 19:05:01 volumio volumio[31310]: info: Scanning category music_service Jan 28 19:05:01 volumio volumio[31310]: info: Plugin folders cleanup completed Jan 28 19:05:01 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:05:01 volumio volumio[31310]: info: ----- Core plugins startup ---- Jan 28 19:05:01 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:05:01 volumio volumio[31310]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 19:05:01 volumio volumio[31310]: info: Adding plugin upnp to MyMusic Plugins Jan 28 19:05:01 volumio volumio[31310]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 19:05:01 volumio volumio[31310]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 19:05:01 volumio volumio[31310]: info: Loading plugins from folder /data/plugins/ Jan 28 19:05:01 volumio volumio[31310]: info: Loading plugin "system"... Jan 28 19:05:01 volumio volumio[31310]: info: Loading plugin "appearance"... Jan 28 19:05:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 19:05:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:02 volumio go-librespot[31346]: go-librespot daemon starting... Jan 28 19:05:02 volumio go-librespot[31347]: time="2026-01-28T19:05:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:02 volumio go-librespot[31347]: time="2026-01-28T19:05:02+07:00" level=debug msg="app state loaded" Jan 28 19:05:02 volumio go-librespot[31347]: time="2026-01-28T19:05:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "network"... Jan 28 19:05:03 volumio volumio[31310]: info: Refreshing Cached IP Addresses Jan 28 19:05:03 volumio sudo[31355]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 19:05:03 volumio sudo[31355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:03 volumio sudo[31357]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 19:05:03 volumio sudo[31357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "services"... Jan 28 19:05:03 volumio sudo[31355]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "alsa_controller"... Jan 28 19:05:03 volumio sudo[31357]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:05:03 volumio sudo[31364]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 19:05:03 volumio sudo[31364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=info msg="zeroconf server listening on port 40573" Jan 28 19:05:03 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "wizard"... Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "networkfs"... Jan 28 19:05:03 volumio volumio[31310]: info: Starting Udev Watcher for removable devices Jan 28 19:05:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:03 volumio volumio[31310]: info: Ignoring mount for partition: boot Jan 28 19:05:03 volumio volumio[31310]: info: Ignoring mount for partition: volumio Jan 28 19:05:03 volumio volumio[31310]: info: Ignoring mount for partition: volumio_data Jan 28 19:05:03 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "volumio_command_line_client"... Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "upnp"... Jan 28 19:05:03 volumio volumio[31310]: info: [1769601903666] Starting Upmpd Daemon Jan 28 19:05:03 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "my_music"... Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="obtained new client token: AAA2rLwCkPvmzsmMRW8FHjIFLIRwuplJeUNUv3FUQKGYqzoWHt9LqE8cv6vK3yhqLqPkQJTKivEnYrt3meALvltj39yg2M5ypX9VdjttAX1x9JswkrGQn3C+bFUb8tK4SbUykQwQ66AUQVSTQcl93niCzvx/qDZP2KpHIXu6iLux4MfqRta6mkEQBU1djD33ICbkFJBKNNQfAX4m5XeyyxQ12uia1E3Q8I1koJspjOgr01vHqSwVZm9xre8=" Jan 28 19:05:03 volumio volumio[31310]: info: Loading plugin "mpd"... Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=debug msg="completed challenge" Jan 28 19:05:03 volumio go-librespot[31347]: time="2026-01-28T19:05:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:04 volumio volumio[31310]: info: Loading plugin "upnp_browser"... Jan 28 19:05:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:06 volumio sudo[31364]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 19:05:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:07 volumio go-librespot[31389]: go-librespot daemon starting... Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=debug msg="app state loaded" Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:07 volumio volumio[31310]: info: Starting UPNP Browser Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "alarm-clock"... Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "airplay_emulation"... Jan 28 19:05:07 volumio volumio[31310]: info: Starting Shairport Sync Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "last_100"... Jan 28 19:05:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "webradio"... Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:05:07 volumio go-librespot[31390]: time="2026-01-28T19:05:07+07:00" level=info msg="zeroconf server listening on port 44667" Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "i2s_dacs"... Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "volumiodiscovery"... Jan 28 19:05:07 volumio volumio[31310]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 19:05:07 volumio volumio[31310]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:05:07 volumio node[31310]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 19:05:07 volumio volumio[31310]: *** WARNING *** For more information see Jan 28 19:05:07 volumio volumio[31310]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 19:05:07 volumio volumio[31310]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:05:07 volumio volumio[31310]: *** WARNING *** For more information see Jan 28 19:05:07 volumio node[31310]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:05:07 volumio node[31310]: *** WARNING *** For more information see Jan 28 19:05:07 volumio node[31310]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 19:05:07 volumio node[31310]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 19:05:07 volumio node[31310]: *** WARNING *** For more information see Jan 28 19:05:07 volumio volumio[31310]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 19:05:07 volumio volumio[31310]: info: Discovery: Started advertising with name: Volumio Jan 28 19:05:07 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 19:05:07 volumio volumio[31310]: info: Loading plugin "spop"... Jan 28 19:05:08 volumio go-librespot[31390]: time="2026-01-28T19:05:08+07:00" level=debug msg="obtained new client token: AABjWH/t3R91w882JpfKO+5KAmTO3b/7kFh3Uf2T/0prJiVorl/pdglRRcTXbhrojmrH8/WQXR6XAuDQf01reySbZFpoEvQIGgoo9+3rf3keQyVDeocQCSpf3sQeW9IKLIiP7Si8ZcNX2g0pvCnpsb+7ktkJ/+ST6jFOLJlr8uZa45V8qIfDFsNeMUcXMC3R478R0Q9bJ1lM/b36/2wl05C4vP99pMsrFVY/PY/+W/VkWR8nrBYYyToEjrk=" Jan 28 19:05:08 volumio go-librespot[31390]: time="2026-01-28T19:05:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:08 volumio go-librespot[31390]: time="2026-01-28T19:05:08+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:08 volumio go-librespot[31390]: time="2026-01-28T19:05:08+07:00" level=debug msg="completed challenge" Jan 28 19:05:08 volumio go-librespot[31390]: time="2026-01-28T19:05:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:09 volumio volumio[31310]: info: Loading plugin "ytcr"... Jan 28 19:05:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 19:05:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:11 volumio go-librespot[31400]: go-librespot daemon starting... Jan 28 19:05:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:11 volumio go-librespot[31401]: time="2026-01-28T19:05:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:11 volumio go-librespot[31401]: time="2026-01-28T19:05:11+07:00" level=debug msg="app state loaded" Jan 28 19:05:11 volumio go-librespot[31401]: time="2026-01-28T19:05:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=info msg="zeroconf server listening on port 37521" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="obtained new client token: AAA0AkQIZhrr7k4gnobenNvODVlLsuXsbmlM3grlaJzcmcx7dKb/58tfCFJ4lzfX0oUTXYqBj/ScJI5aiRKMBa7XL5JgpuaLkgtKkFRcQ5yJe0JtM/Yo/7PqnsSj0cXDOtqcnLB9SSRMBzTcXi/NTGILT8+AO7Rn1dGLJ3THStFCI0UNVvpHP68c0EOMBX313LwJUCHqePJWCBp710PdK94HeQRET+cVEQXKRRlIIt5GIDntjbYWD+B2TKc=" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 19:05:12 volumio volumio[31310]: info: Loading plugin "ytmusic"... Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=debug msg="completed challenge" Jan 28 19:05:12 volumio go-librespot[31401]: time="2026-01-28T19:05:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:13 volumio volumio-remote-updater[628]: [2026-01-28 19:05:13] [connect] Successful connection Jan 28 19:05:13 volumio volumio[31310]: info: Loading plugin "outputs"... Jan 28 19:05:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:13 volumio volumio[31310]: info: Loading plugin "albumart"... Jan 28 19:05:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:13 volumio volumio[31310]: info: Plugin example_plugin is not enabled Jan 28 19:05:13 volumio volumio[31310]: info: Loading plugin "inputs"... Jan 28 19:05:13 volumio volumio[31310]: info: Loading plugin "updater_comm"... Jan 28 19:05:13 volumio volumio[31310]: info: Plugin mpdemulation is not enabled Jan 28 19:05:13 volumio volumio[31310]: info: Loading plugin "rest_api"... Jan 28 19:05:13 volumio volumio[31310]: info: Loading plugin "websocket"... Jan 28 19:05:13 volumio volumio[31310]: info: Starting Socket.io Server version 1.7.4 Jan 28 19:05:14 volumio volumio[31310]: info: Loading plugin "RoonBridge"... Jan 28 19:05:14 volumio volumio[31310]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 19:05:14 volumio volumio[31310]: info: Loading i18n strings for locale en Jan 28 19:05:14 volumio volumio[31310]: Updating browse sources language Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:05:14 volumio volumio[31423]: Forking 3 albumart workers Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::initPlayerControls Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 19:05:14 volumio volumio[31310]: Express server listening on port 3000 Jan 28 19:05:14 volumio volumio[31310]: [Metrics] WebUI: 16s 48.94ms Jan 28 19:05:14 volumio volumio[31310]: info: CoreStateMachine::resetVolumioState Jan 28 19:05:14 volumio volumio[31310]: info: CoreStateMachine::getcurrentVolume Jan 28 19:05:14 volumio volumio[31310]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 19:05:15 volumio sudo[31465]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 19:05:15 volumio sudo[31465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:15 volumio sudo[31468]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 19:05:15 volumio sudo[31465]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:15 volumio sudo[31468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:15 volumio sudo[31468]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:15 volumio volumio[31310]: info: Volumio Network Manager: Network status updated: 1 Jan 28 19:05:15 volumio volumio[31310]: info: VolumeController:: Volume=100 Mute =false Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::pushState Jan 28 19:05:15 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::volumioPushState Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::updateTrackBlock Jan 28 19:05:15 volumio volumio[31310]: info: CorePlayQueue::getTrackBlock Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 19:05:15 volumio volumio-remote-updater[628]: [2026-01-28 19:05:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769601913 101 Jan 28 19:05:15 volumio volumio[31310]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:15 volumio volumio[31310]: info: Reloading queue from file Jan 28 19:05:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::setRepeat null single undefined Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::pushState Jan 28 19:05:15 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::volumioPushState Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::setRandom null Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::pushState Jan 28 19:05:15 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::volumioPushState Jan 28 19:05:15 volumio volumio[31310]: info: Setting Device type: Raspberry PI Jan 28 19:05:15 volumio volumio[31310]: info: Completed loading Core Plugins Jan 28 19:05:15 volumio volumio[31310]: info: Preparing to generate the ALSA configuration file Jan 28 19:05:15 volumio volumio[31310]: info: VolumeController:: Volume=100 Mute =false Jan 28 19:05:15 volumio volumio[31310]: info: CoreStateMachine::pushState Jan 28 19:05:15 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::volumioPushState Jan 28 19:05:15 volumio volumio[31310]: info: Asound.conf file unchanged, so no further update is needed Jan 28 19:05:15 volumio volumio[31310]: info: Output device has changed, restarting MPD Jan 28 19:05:15 volumio volumio[31310]: info: Output device has changed, restarting Shairport Sync Jan 28 19:05:15 volumio sudo[31484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 19:05:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:15 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:16 volumio sudo[31484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:16 volumio sudo[31486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 19:05:16 volumio sudo[31488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 19:05:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:16 volumio go-librespot[31489]: go-librespot daemon starting... Jan 28 19:05:16 volumio sudo[31486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:16 volumio sudo[31488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:16 volumio sudo[31486]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:16 volumio volumio[31310]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=debug msg="app state loaded" Jan 28 19:05:16 volumio sudo[31484]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:16 volumio volumio[31310]: info: ___________ START PLUGINS ___________ Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:16 volumio volumio[31310]: info: ControllerMpd::onStart: Initializing MPD Jan 28 19:05:16 volumio volumio[31310]: info: Creating MPD Configuration file Jan 28 19:05:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:05:16 volumio volumio[31310]: info: [1769601916342] CoreMusicLibrary::Adding element Media Servers Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:05:16 volumio sudo[31506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 19:05:16 volumio sudo[31506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 19:05:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 19:05:16 volumio systemd[1]: mpd.service: Consumed 7.349s CPU time. Jan 28 19:05:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 19:05:16 volumio sudo[31504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 19:05:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 19:05:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 19:05:16 volumio sudo[31504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:16 volumio volumio[31310]: info: UPNP Browser: Client initialized successfully Jan 28 19:05:16 volumio sudo[31504]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 19:05:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 19:05:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 19:05:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 19:05:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 19:05:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 19:05:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 19:05:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 19:05:16 volumio volumio[31310]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:16 volumio volumio[31310]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:05:16 volumio volumio[31310]: info: [1769601916835] CoreMusicLibrary::Adding element Last_100 Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:05:16 volumio volumio[31310]: info: [1769601916848] CoreMusicLibrary::Adding element Webradio Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:05:16 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 19:05:16 volumio volumio[31310]: info: Initializing BBC Radios Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 19:05:16 volumio go-librespot[31495]: time="2026-01-28T19:05:16+07:00" level=info msg="zeroconf server listening on port 43693" Jan 28 19:05:17 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 19:05:17 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:17 volumio volumio[31310]: info: Creating Spotify config file Jan 28 19:05:17 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:17 volumio go-librespot[31495]: time="2026-01-28T19:05:17+07:00" level=debug msg="obtained new client token: AAC2XsjMf3Dzf3vbkPCZx7KyUHxHZQnRZIzepoN/1ZH6VY9p/A/CbFESwULY7SyD2DbQ+LjvYI71Uh3Vshc1EEEkf7Lu+/i+QUOkTJklY4J6ybCzBafG9M7ZLhnD6NsH4Ml7vYW5xL8Tqc/oHfY24r1kgwwpxNS6AV1SZS8hyO/9rV4G8ZQmfGa9a0BLd49/0fCaNfNgUJAyWJJI4n1iaxNyP3Iol1lkUkkOPqDjYIOK+MKlpFlxepcR" Jan 28 19:05:17 volumio sudo[31518]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 19:05:17 volumio sudo[31518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 19:05:17 volumio sudo[31518]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:17 volumio go-librespot[31495]: time="2026-01-28T19:05:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:17 volumio go-librespot[31495]: time="2026-01-28T19:05:17+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:17 volumio go-librespot[31495]: time="2026-01-28T19:05:17+07:00" level=debug msg="completed challenge" Jan 28 19:05:17 volumio go-librespot[31495]: time="2026-01-28T19:05:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:18 volumio volumio[31433]: Starting albumart workers Jan 28 19:05:18 volumio volumio[31310]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:05:18 volumio volumio[31310]: info: [1769601918303] CoreMusicLibrary::Adding element YouTube Music Jan 28 19:05:18 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:05:18 volumio volumio[31310]: Cannot find translation for source YouTube Music Jan 28 19:05:18 volumio volumio[31434]: Starting albumart workers Jan 28 19:05:18 volumio volumio[31310]: info: Volumio Calling Home Jan 28 19:05:18 volumio sudo[31539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 19:05:18 volumio sudo[31539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:18 volumio sudo[31539]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:18 volumio volumio[31435]: Starting albumart workers Jan 28 19:05:19 volumio volumio[31310]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 19:05:19 volumio volumio[31310]: info: Discovery: Found device Volumio Jan 28 19:05:19 volumio volumio[31310]: info: CoreCommandRouter::volumioGetState Jan 28 19:05:19 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:19 volumio volumio[31310]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 19:05:19 volumio volumio[31310]: info: Discovery: Found device Volumio Jan 28 19:05:19 volumio volumio[31310]: info: CoreCommandRouter::volumioGetState Jan 28 19:05:19 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:19 volumio volumio[31310]: info: MPD Permissions set Jan 28 19:05:19 volumio volumio[31310]: info: MPD Permissions set Jan 28 19:05:19 volumio volumio[31310]: info: Upmpdcli Daemon Started Jan 28 19:05:19 volumio volumio[31310]: info: Volumio called home Jan 28 19:05:19 volumio volumio[31310]: info: Spotify config file written Jan 28 19:05:19 volumio sudo[31545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 19:05:19 volumio sudo[31545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:19 volumio go-librespot[31547]: go-librespot daemon starting... Jan 28 19:05:19 volumio sudo[31545]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:19 volumio go-librespot[31548]: time="2026-01-28T19:05:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:19 volumio go-librespot[31548]: time="2026-01-28T19:05:19+07:00" level=debug msg="app state loaded" Jan 28 19:05:19 volumio go-librespot[31548]: time="2026-01-28T19:05:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:20 volumio volumio[31310]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 19:05:20 volumio go-librespot[31548]: time="2026-01-28T19:05:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 19:05:20 volumio go-librespot[31548]: time="2026-01-28T19:05:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 19:05:20 volumio go-librespot[31548]: time="2026-01-28T19:05:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio go-librespot[31548]: time="2026-01-28T19:05:20+07:00" level=info msg="zeroconf server listening on port 41565" Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 19:05:20 volumio volumio[31310]: info: No need to fix Spotify hosts Jan 28 19:05:20 volumio go-librespot[31548]: time="2026-01-28T19:05:20+07:00" level=debug msg="obtained new client token: AABT3eXJdKF86HYL7SZ0jzHFMwgz7Mr/erIOGyuHt0CFe+wHSefxiJuLjMxGeo58VIcitAORuuAlTqqffME9S4KkkeyzeDcX5ngCcXPfbz1U5B8Ht1H14p3SLyQPG1uXfdi2UrgV1z9QPHTRkpACDwaMfPP5sKmdkBs09W0lyp4NqtonjmsBPeYL3OwNM8Ia/Wph89ZbwRfOR0CsNrYURh/DnDqVanYE6BXysonlAT/wBdNE/aRuLV8hbOk=" Jan 28 19:05:20 volumio go-librespot[31548]: time="2026-01-28T19:05:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:21 volumio go-librespot[31548]: time="2026-01-28T19:05:21+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:21 volumio go-librespot[31548]: time="2026-01-28T19:05:21+07:00" level=debug msg="completed challenge" Jan 28 19:05:21 volumio volumio[31310]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 19:05:21 volumio volumio[31310]: SPOTIFY: BQBwR-6SsKlsmP-j4rDPbwVyp4Wzlc9jqzpANtGd2AZQHyJA7YQdq3hWOuRdyRRS_yFPkRwl5Zy2EmMiyu3s0Ro5XEsrvMHp43K0JMxQws_FIVOTK4UtOHQAOGmwDQDTblLYVwFyJUMuVz_5zl_0oUVyqi48ESIyPDOQrltiKIsGZptCARY7eGuUs-gc4v1RfFJfzJ6c2rXBxLBO7b6OvdiWoJWCCDsPvHiZK4Kzc4JUVBQASLjzOrpDvTH-jWAf_K1OlPbiBznQBivsk9YtQ7-1rhZwUrM0MCQSai_QtsaFUixFZ6GZpHSz Jan 28 19:05:21 volumio volumio[31310]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 19:05:21 volumio volumio[31310]: info: New Spotify access token = BQBwR-6SsKlsmP-j4rDPbwVyp4Wzlc9jqzpANtGd2AZQHyJA7YQdq3hWOuRdyRRS_yFPkRwl5Zy2EmMiyu3s0Ro5XEsrvMHp43K0JMxQws_FIVOTK4UtOHQAOGmwDQDTblLYVwFyJUMuVz_5zl_0oUVyqi48ESIyPDOQrltiKIsGZptCARY7eGuUs-gc4v1RfFJfzJ6c2rXBxLBO7b6OvdiWoJWCCDsPvHiZK4Kzc4JUVBQASLjzOrpDvTH-jWAf_K1OlPbiBznQBivsk9YtQ7-1rhZwUrM0MCQSai_QtsaFUixFZ6GZpHSz Jan 28 19:05:21 volumio go-librespot[31548]: time="2026-01-28T19:05:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:21 volumio volumio[31310]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 19:05:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:21 volumio volumio[31310]: info: Starting Shairport Sync Jan 28 19:05:21 volumio volumio[31310]: info: Starting Shairport Sync Jan 28 19:05:21 volumio volumio[31310]: info: Starting Shairport Sync Jan 28 19:05:21 volumio sudo[31586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 19:05:21 volumio sudo[31586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:21 volumio sudo[31588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 19:05:21 volumio sudo[31588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:21 volumio sudo[31590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 19:05:21 volumio sudo[31590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 19:05:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 19:05:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 19:05:21 volumio systemd[1]: shairport-sync.service: Consumed 2.367s CPU time. Jan 28 19:05:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 19:05:21 volumio sudo[31586]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 19:05:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 19:05:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 19:05:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 19:05:21 volumio sudo[31588]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:21 volumio sudo[31590]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:21 volumio volumio[31310]: info: Shairport-Sync Started Jan 28 19:05:21 volumio volumio[31310]: Error adding Membership: Error: addMembership EINVAL Jan 28 19:05:21 volumio volumio[31310]: info: Shairport-Sync Started Jan 28 19:05:21 volumio volumio[31310]: info: Shairport-Sync Started Jan 28 19:05:22 volumio volumio[31310]: info: CoreCommandRouter::volumioGetState Jan 28 19:05:22 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:22 volumio volumio[31310]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 19:05:22 volumio volumio[31310]: info: Spotify Successfully logged in Jan 28 19:05:22 volumio volumio[31310]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 19:05:22 volumio volumio[31310]: info: [1769601922269] CoreMusicLibrary::Adding element Spotify Jan 28 19:05:22 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 19:05:22 volumio volumio[31310]: Cannot find translation for source YouTube Music Jan 28 19:05:22 volumio volumio[31310]: Cannot find translation for source Spotify Jan 28 19:05:22 volumio volumio[31310]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 19:05:22 volumio volumio[31310]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 19:05:23 volumio volumio[31310]: info: VolumeController:: Volume=100 Mute =false Jan 28 19:05:23 volumio volumio[31310]: info: CoreCommandRouter::volumioGetState Jan 28 19:05:23 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:23 volumio volumio[31310]: info: CoreStateMachine::pushState Jan 28 19:05:23 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:23 volumio volumio[31310]: info: CoreCommandRouter::volumioPushState Jan 28 19:05:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:24 volumio volumio[31310]: info: go-librespot daemon successfully initialized Jan 28 19:05:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 19:05:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:24 volumio mpd[31537]: 2026-01-28T19:05:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 19:05:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:24 volumio go-librespot[31628]: go-librespot daemon starting... Jan 28 19:05:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 19:05:24 volumio sudo[31488]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:24 volumio sudo[31506]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=debug msg="app state loaded" Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:24 volumio volumio[31310]: error: MPD error: The expression evaluated to a falsy value: Jan 28 19:05:24 volumio volumio[31310]: assert.ok(self.idling) Jan 28 19:05:24 volumio volumio[31310]: error: The expression evaluated to a falsy value: Jan 28 19:05:24 volumio volumio[31310]: assert.ok(self.idling) Jan 28 19:05:24 volumio volumio[31310]: info: Completed starting Core Plugins Jan 28 19:05:24 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:05:24 volumio volumio[31310]: info: ----- MyVolumio plugins startup ---- Jan 28 19:05:24 volumio volumio[31310]: info: ------------------------------------------- Jan 28 19:05:24 volumio volumio[31310]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 19:05:24 volumio volumio[31310]: info: MPD running with PID31537 Jan 28 19:05:24 volumio volumio[31310]: ,establishing connection Jan 28 19:05:24 volumio volumio[31310]: error: updateQueue error: null Jan 28 19:05:24 volumio volumio[31310]: error: updateQueue error: null Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 19:05:24 volumio go-librespot[31631]: time="2026-01-28T19:05:24+07:00" level=info msg="zeroconf server listening on port 37433" Jan 28 19:05:25 volumio go-librespot[31631]: time="2026-01-28T19:05:25+07:00" level=debug msg="obtained new client token: AADsW0wTG55ZqeRIlIcPjxJ5cSGRFg3q4leyS9fRXjUN9wJi/SzWWYlsz21h2kzim0SgFRKDKp/AiUQxYT3vBjgnnlZlJJPLVIwJOQGONmNkMlexDUEzuaDPJ8JiVl+9lXC01EJFWB1ieylm+oZPhq6PIBxqVFAvv4pu/av0IlgMopnG1DtSHaBJraXG4nF0MhDYT7+MXZ6kld2BkKI5lY2BuUDkYDw/UF+ztbAsdZ9YmaXu1u3NRGwc" Jan 28 19:05:25 volumio go-librespot[31631]: time="2026-01-28T19:05:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:25 volumio go-librespot[31631]: time="2026-01-28T19:05:25+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:25 volumio go-librespot[31631]: time="2026-01-28T19:05:25+07:00" level=debug msg="completed challenge" Jan 28 19:05:25 volumio go-librespot[31631]: time="2026-01-28T19:05:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:27 volumio volumio[31310]: info: Initializing connection to go-librespot Websocket Jan 28 19:05:27 volumio volumio[31310]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:05:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 19:05:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:28 volumio go-librespot[31640]: go-librespot daemon starting... Jan 28 19:05:28 volumio go-librespot[31641]: time="2026-01-28T19:05:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:28 volumio go-librespot[31641]: time="2026-01-28T19:05:28+07:00" level=debug msg="app state loaded" Jan 28 19:05:28 volumio go-librespot[31641]: time="2026-01-28T19:05:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=info msg="zeroconf server listening on port 45413" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="obtained new client token: AACJP/4yvK9upRZmFjaTeUvRuQcjrQ5AIxs2dHaVz1Th2+eu5pJBPuP3TfL5jZTqrsZqYV7jcdsvTbHjDwlw9aNk1JJKBkENeh6cFGmaPetlFkCvlFLn+Mod1iuJx0gXEDiNY6SGUKaXJjw7on6l9KYNNnBn3XTFQxOQI9pZKVgfXJGiVrjY04F+2Z2fDRJY/qMhDgyoj6XC2w4+3AaIp3lTfzln51VvEAUmZ9AdLOi/d17jH++H3rreB0A=" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:29 volumio volumio[31310]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05:29+07:00" level=debug msg="completed challenge" Jan 28 19:05:29 volumio go-librespot[31641]: time="2026-01-28T19:05: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 28 19:05:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:30 volumio volumio[31310]: info: Initializing connection to go-librespot Websocket Jan 28 19:05:30 volumio volumio[31310]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 19:05:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 19:05:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:32 volumio go-librespot[31648]: go-librespot daemon starting... Jan 28 19:05:32 volumio go-librespot[31649]: time="2026-01-28T19:05:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:32 volumio go-librespot[31649]: time="2026-01-28T19:05:32+07:00" level=debug msg="app state loaded" Jan 28 19:05:32 volumio go-librespot[31649]: time="2026-01-28T19:05:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:33 volumio volumio[31310]: info: Initializing connection to go-librespot Websocket Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05:33+07:00" level=debug msg="new websocket client" Jan 28 19:05:33 volumio volumio[31310]: info: Connection to go-librespot Websocket established Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05: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 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05: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 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05: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 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05:33+07:00" level=info msg="zeroconf server listening on port 42979" Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 19:05:33 volumio volumio[31310]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 19:05:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05:33+07:00" level=debug msg="obtained new client token: AAA9dVbZO8NNOnBgswPKV8nN9Mjl+Qgj0Ert7c+y/8Wzrdv+lX1KQOdj+5CU0ev4DPYaLfAuHlHBi1Mmb//fzWDaecOeQwogPHL9Me8Oa9+/eqNA9N14W4RMrlV4H/pYsDDGO17nABIPSstmvutZe8SPubaWzuE6P452QTNRCygkxY2MPU5QyD9mxHOlTEGSvlgmInefUSpn/YvK0rvn+/9n7K4z3B+UZL2BT97obkTnCZQn0/o13HgSs7M=" Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05:33+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05:33+07:00" level=debug msg="completed challenge" Jan 28 19:05:33 volumio go-librespot[31649]: time="2026-01-28T19:05: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 28 19:05:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:35 volumio volumio[31310]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 19:05:35 volumio volumio[31310]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 19:05:35 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:35 volumio volumio[31310]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 19:05:35 volumio volumio[31310]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 19:05:35 volumio volumio[31310]: info: MyVolumio login type: Token Jan 28 19:05:35 volumio volumio[31310]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 19:05:35 volumio volumio[31310]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 19:05:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 28 19:05:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 19:05:37 volumio go-librespot[31671]: go-librespot daemon starting... Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=debug msg="app state loaded" Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 19:05:37 volumio volumio[31310]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 19:05:37 volumio volumio[31310]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 19:05:37 volumio volumio[31310]: info: Streaming services startup Jan 28 19:05:37 volumio volumio[31310]: info: Starting Streaming Daemon Jan 28 19:05:37 volumio sudo[31680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 19:05:37 volumio sudo[31680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 19:05:37 volumio volumio[31310]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 19:05:37 volumio sudo[31680]: pam_unix(sudo:session): session closed for user root Jan 28 19:05:37 volumio volumio[31310]: info: Getting Spotify volume Jan 28 19:05:37 volumio volumio[31310]: info: Connection to go-librespot Websocket closed Jan 28 19:05:37 volumio volumio[31310]: error: Cannot start Volumio Streaming Daemon Jan 28 19:05:37 volumio volumio[31310]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 19:05:37 volumio volumio[31310]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 19:05:37 volumio volumio[31310]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 19:05:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 19:05:37 volumio volumio[31310]: info: CoreCommandRouter::volumioGetState Jan 28 19:05:37 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=info msg="zeroconf server listening on port 33107" Jan 28 19:05:37 volumio volumio[31310]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 19:05:37 volumio volumio[31310]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 19:05:37 volumio volumio[31310]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 19:05:37 volumio volumio[31310]: info: Aligning Spotify Volume to Volumio Volume Jan 28 19:05:37 volumio volumio[31310]: info: CoreCommandRouter::volumioGetState Jan 28 19:05:37 volumio volumio[31310]: info: CorePlayQueue::getTrack 0 Jan 28 19:05:37 volumio volumio[31310]: info: Setting Spotify Volume from Volumio: 100 Jan 28 19:05:37 volumio go-librespot[31672]: time="2026-01-28T19:05:37+07:00" level=debug msg="obtained new client token: AADd/QMwPH4ko6UhGXIDHuWoPK6e2+xj/Njlls8GBiG6YadrJBpBcxdxW50miYKZCbwzro3Y1m6/3mtR2u2r8O90tTWtswHTOVVRzbA7uzd0UkUPLsxw3OdYpw8R1t/WHm8YfBQm8VhCGoDhY7vE7U78pRxQ8Nxl2k/4aVZFtaeEKEkY9f+uEpXymXAqMB2jBYayYFEh5xbYGXAWuXcJ/29UL0vkazsRapaTmraH+jbbxkNEySDrp6o2U2g=" Jan 28 19:05:38 volumio go-librespot[31672]: time="2026-01-28T19:05:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 19:05:38 volumio go-librespot[31672]: time="2026-01-28T19:05:38+07:00" level=debug msg="completed keyexchange" Jan 28 19:05:38 volumio go-librespot[31672]: time="2026-01-28T19:05:38+07:00" level=debug msg="completed challenge" Jan 28 19:05:38 volumio go-librespot[31672]: time="2026-01-28T19:05:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 19:05:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 19:05:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 19:05:38 volumio volumio[31310]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 19:05:38 volumio volumio[31310]: Error: socket hang up Jan 28 19:05:38 volumio volumio[31310]: at connResetException (node:internal/errors:720:14) Jan 28 19:05:38 volumio volumio[31310]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 19:05:38 volumio volumio[31310]: at Socket.emit (node:events:526:35) Jan 28 19:05:38 volumio volumio[31310]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 19:05:38 volumio volumio[31310]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 19:05:38 volumio volumio[31310]: code: 'ECONNRESET', Jan 28 19:05:38 volumio volumio[31310]: response: undefined Jan 28 19:05:38 volumio volumio[31310]: } Jan 28 19:05:38 volumio volumio[31310]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 19:05:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 19:05:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 19:05:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 19:05:39 volumio sudo[31700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 19:04' Jan 28 19:05:39 volumio sudo[31700]: 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"