Jan 26 14:14:00 volumio volumio[13053]: error: MPD error: The expression evaluated to a falsy value: Jan 26 14:14:00 volumio volumio[13053]: assert.ok(self.idling) Jan 26 14:14:00 volumio volumio[13053]: error: The expression evaluated to a falsy value: Jan 26 14:14:00 volumio volumio[13053]: assert.ok(self.idling) Jan 26 14:14:00 volumio volumio[13053]: error: updateQueue error: null Jan 26 14:14:00 volumio volumio[13053]: info: Completed starting Core Plugins Jan 26 14:14:00 volumio volumio[13053]: info: ------------------------------------------- Jan 26 14:14:00 volumio volumio[13053]: info: ----- MyVolumio plugins startup ---- Jan 26 14:14:00 volumio volumio[13053]: info: ------------------------------------------- Jan 26 14:14:00 volumio volumio[13053]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 14:14:00 volumio volumio[13053]: info: MPD running with PID13283 Jan 26 14:14:00 volumio volumio[13053]: ,establishing connection Jan 26 14:14:00 volumio volumio[13053]: error: updateQueue error: null Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=info msg="zeroconf server listening on port 36267" Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=debug msg="obtained new client token: AACDqJ9DjBkhwlv2IJpd4aO0vNeINmNGUxd/k8v/Yqsnzw9Bro3XKiUaZ5uhQIYDMInawmI+ik6FSGSJTMkDWX43jkL95DqRlhN+fdmzDXxm6AdF1x5FDdoKcrA3W2wpK+pvp2Ux9i6nM9l02KMwPpK948xgAASoVdVAzhZ2l80zrjmm/xVgkHOphfLXtU8J/nI8qgvaWx71E/f78/vmUQVS5OKtd/RuL1t0JuAZLJKIy8LBGGDDhSxWWkY=" Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:00 volumio go-librespot[13383]: time="2026-01-26T14:14:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:02 volumio volumio[13053]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:02 volumio volumio[13053]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:14:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 14:14:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:04 volumio go-librespot[13393]: go-librespot daemon starting... Jan 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+07:00" level=debug msg="app state loaded" Jan 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+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 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+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 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+07:00" level=info msg="zeroconf server listening on port 43131" Jan 26 14:14:04 volumio go-librespot[13394]: time="2026-01-26T14:14:04+07:00" level=debug msg="obtained new client token: AADsbBPOLVAwfTWQsb7T0bPq1THG5hSAop9U7ep6miWMfkMfOG74nHcXDVrliMfDoXOyUxe4ZWNenmByLDNzWu3f6jazZYPgqC1iy85NAGsDfz17Xhsfbxo0jzGQ8jN2XyN0Kvg2nuQiSbiy8z9nmwuy6NZpnSMV+yGYiEcbB+AO3drUNRtr1bZifLZ6kHCOlv2J6hUrf5ktvpfSrol3mxkUTd1w06VcVWk7aysM+PeJOvbW0BZICp7EWZw=" Jan 26 14:14:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:04 volumio volumio[13053]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 14:14:05 volumio go-librespot[13394]: time="2026-01-26T14:14:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:05 volumio go-librespot[13394]: time="2026-01-26T14:14:05+07:00" level=debug msg="completed keyexchange" Jan 26 14:14:05 volumio go-librespot[13394]: time="2026-01-26T14:14:05+07:00" level=debug msg="completed challenge" Jan 26 14:14:05 volumio go-librespot[13394]: time="2026-01-26T14:14:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 14:14:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:05 volumio volumio[13053]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:05 volumio volumio[13053]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:14:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 14:14:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:08 volumio go-librespot[13401]: go-librespot daemon starting... Jan 26 14:14:08 volumio volumio[13053]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14:08+07:00" level=debug msg="app state loaded" Jan 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:08 volumio volumio[13053]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14: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 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14: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 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14: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 26 14:14:08 volumio go-librespot[13402]: time="2026-01-26T14:14:08+07:00" level=info msg="zeroconf server listening on port 43445" Jan 26 14:14:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 14:14:09 volumio volumio[13053]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 14:14:09 volumio go-librespot[13402]: time="2026-01-26T14:14:09+07:00" level=debug msg="obtained new client token: AABlvZ+W3U+XDcdUHR7+QSc0YbHt2+pTC/r0R/uSQR7sETVNxGduLJB9iQCo0sMZ+E7m2aZqm6Agha1LbRiobJVD73+EzWEBhQvw7fwOrwKGGce+t+8c3si018UBEGCwFwNQMAhSTpGNuJcNSYVRI7hQgzD+J0DSoknmbHy/Cm7eYJEIInaf1BIaidcwPT6YAqC29HigiBHnXQegIuDcEEtrBm2kmO4zaYrLsqvOkjdHvMXVv6SbylV/" Jan 26 14:14:09 volumio go-librespot[13402]: time="2026-01-26T14:14:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:09 volumio go-librespot[13402]: time="2026-01-26T14:14:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:10 volumio volumio[13053]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 14:14:10 volumio volumio[13053]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 14:14:10 volumio volumio[13053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:10 volumio volumio[13053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:10 volumio volumio[13053]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 14:14:11 volumio volumio[13053]: info: MyVolumio login type: Token Jan 26 14:14:11 volumio volumio[13053]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 14:14:11 volumio volumio[13053]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 14:14:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 14:14:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:12 volumio go-librespot[13424]: go-librespot daemon starting... Jan 26 14:14:12 volumio go-librespot[13425]: time="2026-01-26T14:14:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:12 volumio go-librespot[13425]: time="2026-01-26T14:14:12+07:00" level=debug msg="app state loaded" Jan 26 14:14:12 volumio go-librespot[13425]: time="2026-01-26T14:14:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:12 volumio volumio[13053]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 14:14:12 volumio volumio[13053]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 14:14:12 volumio volumio[13053]: info: Streaming services startup Jan 26 14:14:12 volumio volumio[13053]: info: Starting Streaming Daemon Jan 26 14:14:12 volumio sudo[13432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 14:14:12 volumio sudo[13432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:12 volumio volumio[13053]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 14:14:12 volumio sudo[13432]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:12 volumio volumio[13053]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:12 volumio volumio[13053]: error: Cannot start Volumio Streaming Daemon Jan 26 14:14:12 volumio volumio[13053]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 14:14:12 volumio volumio[13053]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 14:14:12 volumio go-librespot[13425]: time="2026-01-26T14:14:12+07:00" level=debug msg="new websocket client" Jan 26 14:14:12 volumio volumio[13053]: info: Connection to go-librespot Websocket established Jan 26 14:14:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+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 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+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 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+07:00" level=info msg="zeroconf server listening on port 45065" Jan 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+07:00" level=debug msg="obtained new client token: AABpDr4rGqhAOZTAxuwzQL0A90moeA4DdqlOlGXe6NR5TScdDw4KAwMUYlZybExIyKHj6kKvZZTPCIy6DO4pMPRAfHQ1K/0dqvm8M7hdn6Dbndk22DKB1q8MENQfbsxg1VujmtSjtk6Fpk3Zuj/c1eiQsTERYKr2lRXaxESn6KkpGHkaY7S3x9FPy8ylCY2DqZekbeziEY4PeUmjd13LJfP4YOsU4AvyCYs/kZiz1tYiV+v/Z0+TVSX/6/g=" Jan 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:13 volumio go-librespot[13425]: time="2026-01-26T14:14:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:13 volumio volumio[13053]: info: Connection to go-librespot Websocket closed Jan 26 14:14:13 volumio volumio[13053]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 14:14:14 volumio volumio[13053]: info: MyVolumio token set successfully Jan 26 14:14:14 volumio volumio[13053]: info: MYVOLUMIO: Adding device Jan 26 14:14:14 volumio volumio[13053]: info: MYVOLUMIO: Evaluating Server Jan 26 14:14:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:15 volumio volumio[13053]: info: MyVolumio status changed Jan 26 14:14:15 volumio volumio[13053]: info: Streaming services startup Jan 26 14:14:15 volumio volumio[13053]: info: Starting Streaming Daemon Jan 26 14:14:15 volumio volumio[13053]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 14:14:15 volumio volumio[13053]: info: Removing audio output: Jan 26 14:14:15 volumio volumio[13053]: info: Stoppping Tunnel 1 Jan 26 14:14:15 volumio sudo[13461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 14:14:15 volumio sudo[13461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:15 volumio sudo[13463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 26 14:14:15 volumio sudo[13463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:15 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 26 14:14:15 volumio sudo[13461]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:15 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 26 14:14:15 volumio volumio[13053]: error: Cannot start Volumio Streaming Daemon Jan 26 14:14:15 volumio volumio[13053]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 14:14:15 volumio volumio[13053]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 14:14:15 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 26 14:14:15 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 26 14:14:15 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 26 14:14:15 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 26 14:14:15 volumio sudo[13463]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:15 volumio volumio[13053]: info: Setting Geolocation for MyVolumio to as1 Jan 26 14:14:15 volumio volumio[13053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:15 volumio volumio[13053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:15 volumio volumio[13053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:15 volumio volumio[13053]: info: Remote SSH Stopped Jan 26 14:14:16 volumio volumio[13053]: info: Getting Spotify volume Jan 26 14:14:16 volumio volumio[13053]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 14:14:16 volumio volumio[13053]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:14:16 volumio volumio[13053]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 14:14:16 volumio volumio[13053]: errno: -111, Jan 26 14:14:16 volumio volumio[13053]: code: 'ECONNREFUSED', Jan 26 14:14:16 volumio volumio[13053]: syscall: 'connect', Jan 26 14:14:16 volumio volumio[13053]: address: '127.0.0.1', Jan 26 14:14:16 volumio volumio[13053]: port: 9879, Jan 26 14:14:16 volumio volumio[13053]: response: undefined Jan 26 14:14:16 volumio volumio[13053]: } Jan 26 14:14:16 volumio volumio[13053]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 14:14:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 14:14:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:17 volumio go-librespot[13478]: go-librespot daemon starting... Jan 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+07:00" level=debug msg="app state loaded" Jan 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:17 volumio sudo[13488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 14:13' Jan 26 14:14:17 volumio sudo[13488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+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 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+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 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+07:00" level=info msg="zeroconf server listening on port 46719" Jan 26 14:14:17 volumio sudo[13488]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:17 volumio go-librespot[13479]: time="2026-01-26T14:14:17+07:00" level=debug msg="obtained new client token: AAC0lr679yBoOB6c9IDeTK4KDxaqMy0csD8QJ5PMYgakDHm/ceFL6mssY5eLnohAK/AZ0G9nTRVW2HAiiL0TwfGv8krDebsC+hkyEsocEQukVDNzQSBykFsBFFkf5YYDV8ltFd5+5HAD0JVDy6+6hWEmEyfUqAm5au9x8v51XloHZWmnVFGFrX9LDkfyhaenmrbcdWIwxYbYJSgzmRb3LC51aeN3RSYxLu+mngJEnmag0RS9Sks5rfAoMgc=" Jan 26 14:14:17 volumio volumio-remote-updater[628]: [2026-01-26 14:14:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 26 14:14:17 volumio volumio-remote-updater[628]: [2026-01-26 14:14:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 26 14:14:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:18 volumio go-librespot[13479]: time="2026-01-26T14:14:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 14:14:18 volumio systemd[1]: volumio.service: Consumed 1min 10.761s CPU time. Jan 26 14:14:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 14:14:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 14:14:18 volumio go-librespot[13479]: time="2026-01-26T14:14:18+07:00" level=debug msg="completed keyexchange" Jan 26 14:14:18 volumio go-librespot[13479]: time="2026-01-26T14:14:18+07:00" level=debug msg="completed challenge" Jan 26 14:14:18 volumio go-librespot[13479]: time="2026-01-26T14:14:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 14:14:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:18 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7075. Jan 26 14:14:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 14:14:18 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 14:14:18 volumio systemd[1]: volumio.service: Consumed 1min 10.761s CPU time. Jan 26 14:14:18 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 14:14:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 14:14:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 14:14:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:21 volumio go-librespot[13524]: go-librespot daemon starting... Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=debug msg="app state loaded" Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:14:21 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:21 volumio volumio[13507]: info: ----- Volumio3 ---- Jan 26 14:14:21 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:21 volumio volumio[13507]: info: ----- System startup ---- Jan 26 14:14:21 volumio go-librespot[13525]: time="2026-01-26T14:14:21+07:00" level=info msg="zeroconf server listening on port 39705" Jan 26 14:14:21 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:22 volumio go-librespot[13525]: time="2026-01-26T14:14:22+07:00" level=debug msg="obtained new client token: AACP9P4N/Hu/tBoqbCoGoHMeyu6SBgyhcYtY7ynynHas6W++HhXujtWhbZcxPPNLNm7FUVoRyvj1knnh2AiHc/ggL6DG69ILwfM3IFC4R5xISNCW+UGFKzqFMuNaN8uR0toh3pDcakfr3rtV+rogxotTOcMTjdBkC76S6Fg1SO/q2vTpvgOV8NQz8mE0yLzujykzAl9t1QzPTRei7MJqojY2eFG6hEO4R8Gn71TcNi0Yit+dHQMTtYN6" Jan 26 14:14:22 volumio go-librespot[13525]: time="2026-01-26T14:14:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:22 volumio go-librespot[13525]: time="2026-01-26T14:14:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:23 volumio volumio-remote-updater[628]: [2026-01-26 14:14:22] [connect] Successful connection Jan 26 14:14:23 volumio volumio[13507]: info: MYVOLUMIO Environment detected Jan 26 14:14:23 volumio volumio[13507]: info: Plugin folders cleanup Jan 26 14:14:23 volumio volumio[13507]: info: Scanning into folder /volumio/app/plugins/ Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category audio_interface Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category miscellanea Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category music_service Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category plugins.json Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category system_controller Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category user_interface Jan 26 14:14:23 volumio volumio[13507]: info: Scanning into folder /data/plugins/ Jan 26 14:14:23 volumio volumio[13507]: info: Scanning category music_service Jan 26 14:14:23 volumio volumio[13507]: info: Plugin folders cleanup completed Jan 26 14:14:23 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:23 volumio volumio[13507]: info: ----- Core plugins startup ---- Jan 26 14:14:23 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:23 volumio volumio[13507]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 14:14:23 volumio volumio[13507]: info: Adding plugin upnp to MyMusic Plugins Jan 26 14:14:23 volumio volumio[13507]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 14:14:23 volumio volumio[13507]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 14:14:23 volumio volumio[13507]: info: Loading plugins from folder /data/plugins/ Jan 26 14:14:23 volumio volumio[13507]: info: Loading plugin "system"... Jan 26 14:14:23 volumio volumio[13507]: info: Loading plugin "appearance"... Jan 26 14:14:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "network"... Jan 26 14:14:25 volumio volumio[13507]: info: Refreshing Cached IP Addresses Jan 26 14:14:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 14:14:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:25 volumio sudo[13546]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 14:14:25 volumio sudo[13546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:25 volumio sudo[13549]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 14:14:25 volumio sudo[13549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "services"... Jan 26 14:14:25 volumio sudo[13546]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "alsa_controller"... Jan 26 14:14:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:25 volumio go-librespot[13548]: go-librespot daemon starting... Jan 26 14:14:25 volumio sudo[13549]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:25 volumio sudo[13557]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 14:14:25 volumio sudo[13557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:25 volumio go-librespot[13567]: time="2026-01-26T14:14:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:25 volumio go-librespot[13567]: time="2026-01-26T14:14:25+07:00" level=debug msg="app state loaded" Jan 26 14:14:25 volumio go-librespot[13567]: time="2026-01-26T14:14:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:25 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "wizard"... Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "networkfs"... Jan 26 14:14:25 volumio volumio[13507]: info: Starting Udev Watcher for removable devices Jan 26 14:14:25 volumio volumio[13507]: info: Ignoring mount for partition: boot Jan 26 14:14:25 volumio volumio[13507]: info: Ignoring mount for partition: volumio Jan 26 14:14:25 volumio volumio[13507]: info: Ignoring mount for partition: volumio_data Jan 26 14:14:25 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "volumio_command_line_client"... Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "upnp"... Jan 26 14:14:25 volumio volumio[13507]: info: [1769411665894] Starting Upmpd Daemon Jan 26 14:14:25 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "my_music"... Jan 26 14:14:25 volumio volumio[13507]: info: Loading plugin "mpd"... Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+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 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+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 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+07:00" level=info msg="zeroconf server listening on port 35049" Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+07:00" level=debug msg="obtained new client token: AADRiSZc++PgGZujlqNj8UWeWcj9dlG3SsQMgOcvZMODQPtL/nTocKsKUdFTC50iZmEY1145q2LtndOZxiYd/txlLpdg9mZ8is4jQ3rfaX398M8vxAAQWeA9RvQ0itpgL/KqgIlyPJKG8Hu4X6rNTYLbb4sQPB4xjtTqHkCxVWbVWVjKAtqfBvCj1VSeYFedp+VC5rTJIVvkB9PtOBjk8yQTBb8JKTxs+pdg3fb5bAin7lfbvWBNXIvvgLI=" Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:26 volumio volumio[13507]: info: Loading plugin "upnp_browser"... Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+07:00" level=debug msg="completed keyexchange" Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14:26+07:00" level=debug msg="completed challenge" Jan 26 14:14:26 volumio go-librespot[13567]: time="2026-01-26T14:14: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 26 14:14:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:28 volumio sudo[13557]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:29 volumio volumio[13507]: info: Starting UPNP Browser Jan 26 14:14:29 volumio volumio[13507]: info: Loading plugin "alarm-clock"... Jan 26 14:14:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 14:14:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:29 volumio volumio[13507]: info: Loading plugin "airplay_emulation"... Jan 26 14:14:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:29 volumio go-librespot[13587]: go-librespot daemon starting... Jan 26 14:14:29 volumio volumio[13507]: info: Starting Shairport Sync Jan 26 14:14:29 volumio volumio[13507]: info: Loading plugin "last_100"... Jan 26 14:14:29 volumio volumio[13507]: info: Loading plugin "webradio"... Jan 26 14:14:29 volumio go-librespot[13588]: time="2026-01-26T14:14:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:29 volumio go-librespot[13588]: time="2026-01-26T14:14:29+07:00" level=debug msg="app state loaded" Jan 26 14:14:29 volumio go-librespot[13588]: time="2026-01-26T14:14:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:30 volumio volumio[13507]: info: Loading plugin "i2s_dacs"... Jan 26 14:14:30 volumio volumio[13507]: info: Loading plugin "volumiodiscovery"... Jan 26 14:14:30 volumio volumio[13507]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 14:14:30 volumio volumio[13507]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:14:30 volumio volumio[13507]: *** WARNING *** For more information see Jan 26 14:14:30 volumio volumio[13507]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 14:14:30 volumio volumio[13507]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:14:30 volumio volumio[13507]: *** WARNING *** For more information see Jan 26 14:14:30 volumio node[13507]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 14:14:30 volumio node[13507]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:14:30 volumio node[13507]: *** WARNING *** For more information see Jan 26 14:14:30 volumio node[13507]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 14:14:30 volumio node[13507]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:14:30 volumio node[13507]: *** WARNING *** For more information see Jan 26 14:14:30 volumio volumio[13507]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 14:14:30 volumio volumio[13507]: info: Discovery: Started advertising with name: Volumio Jan 26 14:14:30 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 14:14:30 volumio volumio[13507]: info: Loading plugin "spop"... Jan 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14: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 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14: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 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14: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 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14:30+07:00" level=info msg="zeroconf server listening on port 45475" Jan 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14:30+07:00" level=debug msg="obtained new client token: AAACMpMNJKp4lzzhMBIqMuQpTQnGDZGKOrjngrqrfLohrtqaXExlktfkQP6/znQgD/92SJEEOlRpbxm2ySqx7yD30+g3z/YJNnHIj1/ad2nDsGJ5C+sCgGxqsD7rhd9IVfaaMKHqM30YDKJwtVT3vyNKLmr4RH/GvmFBz/fCCWlrw7VIP/4dLjBid9JmIKJUUdNANgkzsxUlc5ru/k+dyfTex8Jh+JpfsSMGI36T+1PmjqlZfb2cS8vzsys=" Jan 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:30 volumio go-librespot[13588]: time="2026-01-26T14:14:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:32 volumio volumio[13507]: info: Loading plugin "ytcr"... Jan 26 14:14:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 14:14:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:34 volumio go-librespot[13597]: go-librespot daemon starting... Jan 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+07:00" level=debug msg="app state loaded" Jan 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+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 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+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 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+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 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+07:00" level=info msg="zeroconf server listening on port 44761" Jan 26 14:14:34 volumio volumio[13507]: info: Loading plugin "ytmusic"... Jan 26 14:14:34 volumio go-librespot[13598]: time="2026-01-26T14:14:34+07:00" level=debug msg="obtained new client token: AABBvV/T324yf9GqFe9bemOk4IzxeJ/BfnhHa7aYhNZA5/ZXlzDa6naxx+eKNgK6xqeLFOd+38zvb9JhHxzh7yPUz9YILsXZkux7FTLrqY9IHBIbfb0/xhf9Ti++sER6KVqhdT1FQr6mWIkjoP8kzRtnyqpXwGem80V0F8Q1tgm/kAXo1rr1rNTUGIMtgN86BtcWbD0KVy5CfqVuAg4qwNj0Pn30FgtNS+LvxPhbjDPSUJZA4228UsUAeJE=" Jan 26 14:14:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:35 volumio go-librespot[13598]: time="2026-01-26T14:14:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:35 volumio go-librespot[13598]: time="2026-01-26T14:14:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:35 volumio volumio-remote-updater[628]: [2026-01-26 14:14:35] [connect] Successful connection Jan 26 14:14:35 volumio volumio[13507]: info: Loading plugin "outputs"... Jan 26 14:14:35 volumio volumio[13507]: info: Loading plugin "albumart"... Jan 26 14:14:35 volumio volumio[13507]: info: Plugin example_plugin is not enabled Jan 26 14:14:35 volumio volumio[13507]: info: Loading plugin "inputs"... Jan 26 14:14:35 volumio volumio[13507]: info: Loading plugin "updater_comm"... Jan 26 14:14:36 volumio volumio[13507]: info: Plugin mpdemulation is not enabled Jan 26 14:14:36 volumio volumio[13507]: info: Loading plugin "rest_api"... Jan 26 14:14:36 volumio volumio[13507]: info: Loading plugin "websocket"... Jan 26 14:14:36 volumio volumio[13507]: info: Starting Socket.io Server version 1.7.4 Jan 26 14:14:36 volumio volumio[13507]: info: Loading plugin "RoonBridge"... Jan 26 14:14:36 volumio volumio[13507]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 14:14:36 volumio volumio[13507]: info: Loading i18n strings for locale en Jan 26 14:14:36 volumio volumio[13507]: Updating browse sources language Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:14:36 volumio volumio[13619]: Forking 3 albumart workers Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::initPlayerControls Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 14:14:36 volumio volumio[13507]: Express server listening on port 3000 Jan 26 14:14:36 volumio volumio[13507]: [Metrics] WebUI: 16s 25.83ms Jan 26 14:14:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::resetVolumioState Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::getcurrentVolume Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 14:14:37 volumio sudo[13661]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 14:14:37 volumio sudo[13661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:37 volumio sudo[13661]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:37 volumio sudo[13663]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 14:14:37 volumio sudo[13663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:37 volumio sudo[13663]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:37 volumio volumio[13507]: info: Volumio Network Manager: Network status updated: 1 Jan 26 14:14:37 volumio volumio[13507]: info: VolumeController:: Volume=100 Mute =false Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::pushState Jan 26 14:14:37 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::volumioPushState Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::updateTrackBlock Jan 26 14:14:37 volumio volumio[13507]: info: CorePlayQueue::getTrackBlock Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 14:14:37 volumio volumio-remote-updater[628]: [2026-01-26 14:14:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769411675 101 Jan 26 14:14:37 volumio volumio[13507]: 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 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:37 volumio volumio[13507]: info: Reloading queue from file Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::setRepeat null single undefined Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::pushState Jan 26 14:14:37 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::volumioPushState Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::setRandom null Jan 26 14:14:37 volumio volumio[13507]: info: CoreStateMachine::pushState Jan 26 14:14:37 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:37 volumio volumio[13507]: info: CoreCommandRouter::volumioPushState Jan 26 14:14:37 volumio volumio[13507]: info: Setting Device type: Raspberry PI Jan 26 14:14:37 volumio volumio[13507]: info: Completed loading Core Plugins Jan 26 14:14:37 volumio volumio[13507]: info: Preparing to generate the ALSA configuration file Jan 26 14:14:38 volumio volumio[13507]: info: VolumeController:: Volume=100 Mute =false Jan 26 14:14:38 volumio volumio[13507]: info: CoreStateMachine::pushState Jan 26 14:14:38 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::volumioPushState Jan 26 14:14:38 volumio volumio[13507]: info: Asound.conf file unchanged, so no further update is needed Jan 26 14:14:38 volumio volumio[13507]: info: Output device has changed, restarting MPD Jan 26 14:14:38 volumio volumio[13507]: info: Output device has changed, restarting Shairport Sync Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:38 volumio sudo[13682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 14:14:38 volumio sudo[13682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:38 volumio sudo[13684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 14:14:38 volumio sudo[13684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:38 volumio sudo[13684]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:38 volumio sudo[13686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 14:14:38 volumio volumio[13507]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 14:14:38 volumio sudo[13686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:38 volumio volumio[13507]: info: ___________ START PLUGINS ___________ Jan 26 14:14:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 14:14:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:38 volumio volumio[13507]: info: ControllerMpd::onStart: Initializing MPD Jan 26 14:14:38 volumio volumio[13507]: info: Creating MPD Configuration file Jan 26 14:14:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:38 volumio go-librespot[13694]: go-librespot daemon starting... Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:14:38 volumio volumio[13507]: info: [1769411678384] CoreMusicLibrary::Adding element Media Servers Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:14:38 volumio go-librespot[13697]: time="2026-01-26T14:14:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:38 volumio go-librespot[13697]: time="2026-01-26T14:14:38+07:00" level=debug msg="app state loaded" Jan 26 14:14:38 volumio go-librespot[13697]: time="2026-01-26T14:14:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:38 volumio sudo[13696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 14:14:38 volumio sudo[13696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:38 volumio volumio[13507]: info: UPNP Browser: Client initialized successfully Jan 26 14:14:38 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 14:14:38 volumio sudo[13696]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:38 volumio sudo[13682]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:38 volumio sudo[13703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 14:14:38 volumio sudo[13703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 14:14:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 14:14:38 volumio systemd[1]: mpd.service: Consumed 7.383s CPU time. Jan 26 14:14:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 14:14:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 14:14:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 14:14:38 volumio volumio[13507]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 14:14:38 volumio volumio[13507]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:14:38 volumio volumio[13507]: info: [1769411678798] CoreMusicLibrary::Adding element Last_100 Jan 26 14:14:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:14:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 14:14:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 14:14:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:14:38 volumio volumio[13507]: info: [1769411678859] CoreMusicLibrary::Adding element Webradio Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:14:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 14:14:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 14:14:38 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:14:38 volumio volumio[13507]: info: Initializing BBC Radios Jan 26 14:14:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 14:14:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 14:14:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+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 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+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 26 14:14:39 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:14:39 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=info msg="zeroconf server listening on port 42919" Jan 26 14:14:39 volumio volumio[13507]: info: Creating Spotify config file Jan 26 14:14:39 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=debug msg="obtained new client token: AABBN41PAsYwWPtUmAI+AU4S3uDb0YmgCqeOTtwzNG4myJJPNCAnCIiI+7OlH1Zo5nCY2+lwTTVyQLDMp2CSjkeKS+ofYNaPj68CftYBoFjZRfOYYM1DU3QrXQ+McaS+59fn1SrRpsSe6xk3/DwDVhpODspAkrPIVYQGbF/xKlrky/sMChvq579z96rpiX4MBtE9HyQD261A8RxIV9eQmha9+eGb/XDNFtX06qfTRzEyrjVGCdLYFQXfoiI=" Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:39 volumio sudo[13722]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 14:14:39 volumio sudo[13722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 14:14:39 volumio sudo[13722]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=debug msg="completed keyexchange" Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=debug msg="completed challenge" Jan 26 14:14:39 volumio go-librespot[13697]: time="2026-01-26T14:14:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 14:14:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:40 volumio volumio[13631]: Starting albumart workers Jan 26 14:14:40 volumio volumio[13629]: Starting albumart workers Jan 26 14:14:40 volumio volumio[13507]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:14:40 volumio volumio[13507]: info: [1769411680502] CoreMusicLibrary::Adding element YouTube Music Jan 26 14:14:40 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:14:40 volumio volumio[13507]: Cannot find translation for source YouTube Music Jan 26 14:14:40 volumio volumio[13507]: info: Volumio Calling Home Jan 26 14:14:40 volumio sudo[13736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 14:14:40 volumio sudo[13736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:40 volumio sudo[13736]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:40 volumio volumio[13630]: Starting albumart workers Jan 26 14:14:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:41 volumio volumio[13507]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 14:14:41 volumio volumio[13507]: info: Discovery: Found device Volumio Jan 26 14:14:41 volumio volumio[13507]: info: CoreCommandRouter::volumioGetState Jan 26 14:14:41 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:41 volumio volumio[13507]: info: MPD Permissions set Jan 26 14:14:41 volumio volumio[13507]: info: MPD Permissions set Jan 26 14:14:41 volumio volumio[13507]: info: Upmpdcli Daemon Started Jan 26 14:14:41 volumio volumio[13507]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 14:14:41 volumio volumio[13507]: info: Discovery: Found device Volumio Jan 26 14:14:41 volumio volumio[13507]: info: CoreCommandRouter::volumioGetState Jan 26 14:14:41 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:41 volumio volumio[13507]: info: Volumio called home Jan 26 14:14:41 volumio volumio[13507]: info: Spotify config file written Jan 26 14:14:41 volumio sudo[13742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 14:14:41 volumio sudo[13742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:42 volumio go-librespot[13745]: go-librespot daemon starting... Jan 26 14:14:42 volumio volumio[13507]: 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 26 14:14:42 volumio sudo[13742]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=debug msg="app state loaded" Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:14:42 volumio volumio[13507]: info: No need to fix Spotify hosts Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:14:42 volumio go-librespot[13751]: time="2026-01-26T14:14:42+07:00" level=info msg="zeroconf server listening on port 40231" Jan 26 14:14:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:43 volumio go-librespot[13751]: time="2026-01-26T14:14:43+07:00" level=debug msg="obtained new client token: AADKvWszeMemcx2lG5RyfA8WHSOtSThY0KhvrzuVTfmHRUMwqlJkfhQMzeATcBsjF4VFNfOBPuBGX9l1tkYK6HNSC1X2YMhN4TusplvGKTSjzo8x0RjQ/kNVqlEwEnPVvDmEamI9YeL9bpxBUSW7O1nOPZpKqnGucuq2rEre9o1Pdrb70xsBgbvxslx/UZr66SGh4UD0XT7yp33I+akfZNHnSYppSjflG+57QvVx2jxdjYmwZZvAzxmu" Jan 26 14:14:43 volumio go-librespot[13751]: time="2026-01-26T14:14:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:43 volumio volumio[13507]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 14:14:43 volumio volumio[13507]: SPOTIFY: BQBRcXzyhC_GZchip6-ISCblkIPYUNd5bgSfaAn1CyObhQHfWa8bDqnXxcFHvUXPrg3rIUHC8wMwVoRPj_RHo60bunKSiBp6MkjybsMkqTp2DkA-i-8czJn60HTtrRAbewbGgbeqOImUHjFcWF7NDpEvVYz1mnhd_J3y2B-_Nji8bhQ2tKRQpIOSLmW6GIp0E-mdV6yqG5J1SiChrxXO692Wq5x2EDGQroVTQKuLTfxYDjCS0Xpv_tk8eqWZ6KVXh41yRYmOxW4K22EL3ai8qsiyia_FMML7FLmDfViAkyETVsPWxHS9qUEU Jan 26 14:14:43 volumio volumio[13507]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 14:14:43 volumio volumio[13507]: info: New Spotify access token = BQBRcXzyhC_GZchip6-ISCblkIPYUNd5bgSfaAn1CyObhQHfWa8bDqnXxcFHvUXPrg3rIUHC8wMwVoRPj_RHo60bunKSiBp6MkjybsMkqTp2DkA-i-8czJn60HTtrRAbewbGgbeqOImUHjFcWF7NDpEvVYz1mnhd_J3y2B-_Nji8bhQ2tKRQpIOSLmW6GIp0E-mdV6yqG5J1SiChrxXO692Wq5x2EDGQroVTQKuLTfxYDjCS0Xpv_tk8eqWZ6KVXh41yRYmOxW4K22EL3ai8qsiyia_FMML7FLmDfViAkyETVsPWxHS9qUEU Jan 26 14:14:43 volumio volumio[13507]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 14:14:43 volumio volumio[13507]: info: Starting Shairport Sync Jan 26 14:14:43 volumio go-librespot[13751]: time="2026-01-26T14:14:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:43 volumio volumio[13507]: info: Starting Shairport Sync Jan 26 14:14:43 volumio volumio[13507]: info: Starting Shairport Sync Jan 26 14:14:43 volumio sudo[13782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 14:14:43 volumio sudo[13782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:43 volumio sudo[13784]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 14:14:43 volumio sudo[13784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:43 volumio sudo[13786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 14:14:43 volumio sudo[13786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 14:14:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 14:14:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 14:14:43 volumio systemd[1]: shairport-sync.service: Consumed 2.404s CPU time. Jan 26 14:14:43 volumio volumio[13507]: info: CoreCommandRouter::volumioGetState Jan 26 14:14:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 14:14:43 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:43 volumio sudo[13786]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:43 volumio sudo[13782]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:43 volumio sudo[13784]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:43 volumio volumio[13507]: info: Shairport-Sync Started Jan 26 14:14:43 volumio volumio[13507]: Error adding Membership: Error: addMembership EINVAL Jan 26 14:14:43 volumio volumio[13507]: info: Shairport-Sync Started Jan 26 14:14:43 volumio volumio[13507]: info: Shairport-Sync Started Jan 26 14:14:44 volumio volumio[13507]: 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 26 14:14:44 volumio volumio[13507]: info: Spotify Successfully logged in Jan 26 14:14:44 volumio volumio[13507]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:14:44 volumio volumio[13507]: info: [1769411684102] CoreMusicLibrary::Adding element Spotify Jan 26 14:14:44 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:14:44 volumio volumio[13507]: Cannot find translation for source YouTube Music Jan 26 14:14:44 volumio volumio[13507]: Cannot find translation for source Spotify Jan 26 14:14:44 volumio volumio[13507]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 14:14:44 volumio volumio[13507]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 14:14:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:45 volumio volumio[13507]: info: VolumeController:: Volume=100 Mute =false Jan 26 14:14:45 volumio volumio[13507]: info: CoreCommandRouter::volumioGetState Jan 26 14:14:45 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:45 volumio volumio[13507]: info: CoreStateMachine::pushState Jan 26 14:14:45 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:14:45 volumio volumio[13507]: info: CoreCommandRouter::volumioPushState Jan 26 14:14:46 volumio volumio[13507]: info: go-librespot daemon successfully initialized Jan 26 14:14:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 26 14:14:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:46 volumio go-librespot[13821]: go-librespot daemon starting... Jan 26 14:14:46 volumio go-librespot[13822]: time="2026-01-26T14:14:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:46 volumio go-librespot[13822]: time="2026-01-26T14:14:46+07:00" level=debug msg="app state loaded" Jan 26 14:14:46 volumio go-librespot[13822]: time="2026-01-26T14:14:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:46 volumio mpd[13734]: 2026-01-26T14:14:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 14:14:46 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 14:14:46 volumio sudo[13703]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:46 volumio sudo[13686]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:46 volumio volumio[13507]: error: MPD error: The expression evaluated to a falsy value: Jan 26 14:14:46 volumio volumio[13507]: assert.ok(self.idling) Jan 26 14:14:46 volumio volumio[13507]: error: The expression evaluated to a falsy value: Jan 26 14:14:46 volumio volumio[13507]: assert.ok(self.idling) Jan 26 14:14:47 volumio volumio[13507]: info: MPD running with PID13734 Jan 26 14:14:47 volumio volumio[13507]: ,establishing connection Jan 26 14:14:47 volumio volumio[13507]: error: updateQueue error: null Jan 26 14:14:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:47 volumio volumio[13507]: info: Completed starting Core Plugins Jan 26 14:14:47 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:47 volumio volumio[13507]: info: ----- MyVolumio plugins startup ---- Jan 26 14:14:47 volumio volumio[13507]: info: ------------------------------------------- Jan 26 14:14:47 volumio volumio[13507]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+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 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+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 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=info msg="zeroconf server listening on port 40099" Jan 26 14:14:47 volumio volumio[13507]: error: updateQueue error: null Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=debug msg="obtained new client token: AAC9R2nP5ZOX5L/pmpmKIhype2tA1Rt15+cfOu9XqIgoMhizZRU9EwFKqyhqFDy3T7TiZ8foZG5o4hVx2eatlCKxcaaQ3MLyWnJsWzNfrpmCXPz2LPLv/aW0A8oFJQP1EGq2qoWklyCq3kkFpRAjwvFBAEvkQR8auQucUtIAAfuXbG8yVy7HOq9qto04uf8TlH8myQNksm93xzSIzIB7XQ+ZkQWfhzl/CHPJpFI7gYMo74dZeiSUf3Tx1xI=" Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=debug msg="completed keyexchange" Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=debug msg="completed challenge" Jan 26 14:14:47 volumio go-librespot[13822]: time="2026-01-26T14:14:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 14:14:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:49 volumio volumio[13507]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:49 volumio volumio[13507]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:14:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 26 14:14:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:50 volumio go-librespot[13833]: go-librespot daemon starting... Jan 26 14:14:50 volumio go-librespot[13834]: time="2026-01-26T14:14:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:50 volumio go-librespot[13834]: time="2026-01-26T14:14:50+07:00" level=debug msg="app state loaded" Jan 26 14:14:50 volumio go-librespot[13834]: time="2026-01-26T14:14:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=info msg="zeroconf server listening on port 32771" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="obtained new client token: AADPNVWvfYS5CYs5xMShxhZfILNMdTSaHXkTZjLzrAhvpsJavWPDS2hcs/dMKWIKTG2nk/Zk5T9SYiEg+kkDjXft/KGweZ2WYxFN+z5jiGCJn21yh+Oua4fHfmrHTjHwAyCIDSNxfOzMPSkSccm6ljMJccoTwjFFDE55zTLTcxAFgUdX2q7NbRg9/MBhBWvn1nuOdDATwrypQiwse1xxcogwLmDmlX45oM4CobKrXLpw9O0NMXcsGmjk/PU=" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="completed keyexchange" Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14:51+07:00" level=debug msg="completed challenge" Jan 26 14:14:51 volumio volumio[13507]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 14:14:51 volumio go-librespot[13834]: time="2026-01-26T14:14: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 26 14:14:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:52 volumio volumio[13507]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:52 volumio volumio[13507]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:14:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 26 14:14:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:55 volumio go-librespot[13841]: go-librespot daemon starting... Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=debug msg="app state loaded" Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:55 volumio volumio[13507]: info: Initializing connection to go-librespot Websocket Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=debug msg="new websocket client" Jan 26 14:14:55 volumio volumio[13507]: info: Connection to go-librespot Websocket established Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=info msg="zeroconf server listening on port 35837" Jan 26 14:14:55 volumio go-librespot[13843]: time="2026-01-26T14:14:55+07:00" level=debug msg="obtained new client token: AAAfo4q+4//9Y+7ZmiIdkGIaibGw9WwbSOrRv/4VhM8MvefA4vMoz6f+xc6u3Jto4YaiKjQGlYwmpCxBr03RFSGh4Mo3KEztF2uvDBrpZdsiMGc104g5Tnncj2P4YtTkiQtD60Wu4uOm3Jt1Y3HGqBQtB5t7pWYaQvSb3pdtcwwRWtHRmbmcEdlP0e8L6SDnYQ+TV2JfKtvYDMwyqe8knispDOMiXNWbf5ZXNLdCI2ZDWz/c4Qp9l2N6e38=" Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 14:14:56 volumio go-librespot[13843]: time="2026-01-26T14:14:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:14:56 volumio volumio[13507]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 14:14:56 volumio volumio[13507]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 14:14:56 volumio go-librespot[13843]: time="2026-01-26T14:14:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:14:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:14:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:14:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:57 volumio volumio[13507]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 14:14:57 volumio volumio[13507]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 14:14:57 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:57 volumio volumio[13507]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:14:57 volumio volumio[13507]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 14:14:57 volumio volumio[13507]: info: MyVolumio login type: Token Jan 26 14:14:57 volumio volumio[13507]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 14:14:57 volumio volumio[13507]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 14:14:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:14:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:14:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:14:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 26 14:14:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:14:59 volumio go-librespot[13865]: go-librespot daemon starting... Jan 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14:59+07:00" level=debug msg="app state loaded" Jan 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:14:59 volumio volumio[13507]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 14:14:59 volumio volumio[13507]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 14:14:59 volumio volumio[13507]: info: Streaming services startup Jan 26 14:14:59 volumio volumio[13507]: info: Starting Streaming Daemon Jan 26 14:14:59 volumio sudo[13874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 14:14:59 volumio sudo[13874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:14:59 volumio volumio[13507]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 14:14:59 volumio sudo[13874]: pam_unix(sudo:session): session closed for user root Jan 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14:59+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 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14:59+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 26 14:14:59 volumio go-librespot[13866]: time="2026-01-26T14:14:59+07:00" level=info msg="zeroconf server listening on port 40003" Jan 26 14:15:00 volumio volumio[13507]: info: Getting Spotify volume Jan 26 14:15:00 volumio volumio[13507]: info: Connection to go-librespot Websocket closed Jan 26 14:15:00 volumio volumio[13507]: error: Cannot start Volumio Streaming Daemon Jan 26 14:15:00 volumio volumio[13507]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 14:15:00 volumio volumio[13507]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 14:15:00 volumio go-librespot[13866]: time="2026-01-26T14:15:00+07:00" level=debug msg="obtained new client token: AABoeH19rOklcpNiGHCoNsvhlcaW7OpT6r/pfv88BgANqUF7LhQBw9SBQLv6mlr+CYG+0RVvZ+/Xsp4qDqgrS2xm25fg1Rc2DnBQua0S89iReyVIS+aDuuE9jC5N/fi2OIK52JslTJqARQYYsCz0btHoWQ4lf4EtdvpYOUdeUyg6s0/lz6ct31u6cz0Cdul6/EtHdHLemiOX0YkgWozkS5mWAf9FiGB4PQx39HiQbKZZOTbiX2wk1Xoc" Jan 26 14:15:00 volumio volumio[13507]: 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 26 14:15:00 volumio go-librespot[13866]: time="2026-01-26T14:15:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:00 volumio go-librespot[13866]: time="2026-01-26T14:15:00+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:00 volumio go-librespot[13866]: time="2026-01-26T14:15:00+07:00" level=debug msg="completed challenge" Jan 26 14:15:00 volumio volumio[13507]: info: CoreCommandRouter::volumioGetState Jan 26 14:15:00 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:00 volumio volumio[13507]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 14:15:00 volumio volumio[13507]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 14:15:00 volumio volumio[13507]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 14:15:00 volumio volumio[13507]: info: Aligning Spotify Volume to Volumio Volume Jan 26 14:15:00 volumio volumio[13507]: info: CoreCommandRouter::volumioGetState Jan 26 14:15:00 volumio volumio[13507]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:00 volumio volumio[13507]: info: Setting Spotify Volume from Volumio: 100 Jan 26 14:15:00 volumio go-librespot[13866]: time="2026-01-26T14:15: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 26 14:15:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:00 volumio volumio[13507]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 14:15:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:00 volumio volumio[13507]: Error: socket hang up Jan 26 14:15:00 volumio volumio[13507]: at connResetException (node:internal/errors:720:14) Jan 26 14:15:00 volumio volumio[13507]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 14:15:00 volumio volumio[13507]: at Socket.emit (node:events:526:35) Jan 26 14:15:00 volumio volumio[13507]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 14:15:00 volumio volumio[13507]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 14:15:00 volumio volumio[13507]: code: 'ECONNRESET', Jan 26 14:15:00 volumio volumio[13507]: response: undefined Jan 26 14:15:00 volumio volumio[13507]: } Jan 26 14:15:00 volumio volumio[13507]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 14:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:01 volumio sudo[13895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 14:14' Jan 26 14:15:01 volumio sudo[13895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:02 volumio sudo[13895]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:03 volumio volumio-remote-updater[628]: [2026-01-26 14:15:03] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 26 14:15:03 volumio volumio-remote-updater[628]: [2026-01-26 14:15:03] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 26 14:15:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 26 14:15:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:03 volumio go-librespot[13903]: go-librespot daemon starting... Jan 26 14:15:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 14:15:03 volumio systemd[1]: volumio.service: Consumed 1min 8.260s CPU time. Jan 26 14:15:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 14:15:03 volumio go-librespot[13909]: time="2026-01-26T14:15:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:03 volumio go-librespot[13909]: time="2026-01-26T14:15:03+07:00" level=debug msg="app state loaded" Jan 26 14:15:03 volumio go-librespot[13909]: time="2026-01-26T14:15:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 14:15:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7076. Jan 26 14:15:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 14:15:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 14:15:04 volumio systemd[1]: volumio.service: Consumed 1min 8.260s CPU time. Jan 26 14:15:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 14:15:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+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 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+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 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+07:00" level=info msg="zeroconf server listening on port 40725" Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+07:00" level=debug msg="obtained new client token: AACzta0AiBkpkSNv6VZBTWs3dW11fTzQQHsjDwIusKmWZ4p2ikgKvbKgGptLtQQdeCga8nIwkptIfprr+ZyhOlFW1vcUYM63WPPJyLP0tHfx+F/xLB0xGMqPlnZncaILGuZlX/F1ZKbk0cKeuF00FO3k/Tsv7lpNQrkmqY7Xg8/Fp+TOYKsBzAwGzYMe0vBa+nLQc7VYX0glwRfpI5uCB/5fsI3BswHGVL9tAEX6EZpyChIkbvt6swcn4mU=" Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15:04+07:00" level=debug msg="completed challenge" Jan 26 14:15:04 volumio go-librespot[13909]: time="2026-01-26T14:15: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 26 14:15:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:07 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:07 volumio volumio[13923]: info: ----- Volumio3 ---- Jan 26 14:15:07 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:07 volumio volumio[13923]: info: ----- System startup ---- Jan 26 14:15:07 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 26 14:15:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:08 volumio go-librespot[13945]: go-librespot daemon starting... Jan 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+07:00" level=debug msg="app state loaded" Jan 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:08 volumio volumio-remote-updater[628]: [2026-01-26 14:15:08] [connect] Successful connection Jan 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+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 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+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 26 14:15:08 volumio go-librespot[13946]: time="2026-01-26T14:15:08+07:00" level=info msg="zeroconf server listening on port 38579" Jan 26 14:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:09 volumio go-librespot[13946]: time="2026-01-26T14:15:09+07:00" level=debug msg="obtained new client token: AAD44f7rbR3IysdzEObyfbdMyRaW9J0g+12Y0XzofsnMVZGvOoi/J5GluXhGbLAs2gGu42aeqUEDtIorweKHR+CU3MUKoVIncdFv/LEmN9AvHWrXMq/76cScgfrdTadE1CT7Z5kDVC+LJ/7CpqByrnzA6fuVJ7vNcg20J/pOT/godBExSA22KMx7F2DH7OTWdob80Xyoxwqsfm1n3LG705KvhAdmNem2B5xm+tP8MJNm8r0p/29SKhU2hSk=" Jan 26 14:15:09 volumio volumio[13923]: info: MYVOLUMIO Environment detected Jan 26 14:15:09 volumio go-librespot[13946]: time="2026-01-26T14:15:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:09 volumio go-librespot[13946]: time="2026-01-26T14:15:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:15:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:09 volumio volumio[13923]: info: Plugin folders cleanup Jan 26 14:15:09 volumio volumio[13923]: info: Scanning into folder /volumio/app/plugins/ Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category audio_interface Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category miscellanea Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category music_service Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category plugins.json Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category system_controller Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category user_interface Jan 26 14:15:09 volumio volumio[13923]: info: Scanning into folder /data/plugins/ Jan 26 14:15:09 volumio volumio[13923]: info: Scanning category music_service Jan 26 14:15:09 volumio volumio[13923]: info: Plugin folders cleanup completed Jan 26 14:15:09 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:09 volumio volumio[13923]: info: ----- Core plugins startup ---- Jan 26 14:15:09 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:09 volumio volumio[13923]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 14:15:09 volumio volumio[13923]: info: Adding plugin upnp to MyMusic Plugins Jan 26 14:15:09 volumio volumio[13923]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 14:15:09 volumio volumio[13923]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 14:15:09 volumio volumio[13923]: info: Loading plugins from folder /data/plugins/ Jan 26 14:15:09 volumio volumio[13923]: info: Loading plugin "system"... Jan 26 14:15:09 volumio volumio[13923]: info: Loading plugin "appearance"... Jan 26 14:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "network"... Jan 26 14:15:11 volumio volumio[13923]: info: Refreshing Cached IP Addresses Jan 26 14:15:11 volumio sudo[13961]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 14:15:11 volumio sudo[13961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:11 volumio sudo[13963]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "services"... Jan 26 14:15:11 volumio sudo[13963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:11 volumio sudo[13961]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "alsa_controller"... Jan 26 14:15:11 volumio sudo[13963]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:11 volumio sudo[13970]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 14:15:11 volumio sudo[13970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:11 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "wizard"... Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "networkfs"... Jan 26 14:15:11 volumio volumio[13923]: info: Starting Udev Watcher for removable devices Jan 26 14:15:11 volumio volumio[13923]: info: Ignoring mount for partition: boot Jan 26 14:15:11 volumio volumio[13923]: info: Ignoring mount for partition: volumio Jan 26 14:15:11 volumio volumio[13923]: info: Ignoring mount for partition: volumio_data Jan 26 14:15:11 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "volumio_command_line_client"... Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "upnp"... Jan 26 14:15:11 volumio volumio[13923]: info: [1769411711694] Starting Upmpd Daemon Jan 26 14:15:11 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "my_music"... Jan 26 14:15:11 volumio volumio[13923]: info: Loading plugin "mpd"... Jan 26 14:15:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 26 14:15:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:12 volumio go-librespot[13994]: go-librespot daemon starting... Jan 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15:12+07:00" level=debug msg="app state loaded" Jan 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:12 volumio volumio[13923]: info: Loading plugin "upnp_browser"... Jan 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15:12+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 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15:12+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 26 14:15:12 volumio go-librespot[13995]: time="2026-01-26T14:15:12+07:00" level=info msg="zeroconf server listening on port 44767" Jan 26 14:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:13 volumio go-librespot[13995]: time="2026-01-26T14:15:13+07:00" level=debug msg="obtained new client token: AABOwySMpwwQDXxpFXCuXQKIxbP4MpDYKl+1ZdLRQhK0LXWGKRvkjXiA42q/iuJ3xtmntWLtiPXcLgfoALYZI6zF8X/kTScIi/4hyL5nlV3MOjxFBSL9CcR9AMqse7stiBWpB8CDzFaiOFv8KrNQuuISHB3L6uo9z73FqWPPtcttonvMTihxTOGuExFmMxDOJcya+cYFNLCoLU2s916lK5N16bvzfA1epRK92wqj0iP/9/5Jql0+4xXG" Jan 26 14:15:13 volumio go-librespot[13995]: time="2026-01-26T14:15:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:13 volumio go-librespot[13995]: time="2026-01-26T14:15:13+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:13 volumio go-librespot[13995]: time="2026-01-26T14:15:13+07:00" level=debug msg="completed challenge" Jan 26 14:15:13 volumio go-librespot[13995]: time="2026-01-26T14:15:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 14:15:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:14 volumio sudo[13970]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:15 volumio volumio[13923]: info: Starting UPNP Browser Jan 26 14:15:15 volumio volumio[13923]: info: Loading plugin "alarm-clock"... Jan 26 14:15:15 volumio volumio[13923]: info: Loading plugin "airplay_emulation"... Jan 26 14:15:15 volumio volumio[13923]: info: Starting Shairport Sync Jan 26 14:15:15 volumio volumio[13923]: info: Loading plugin "last_100"... Jan 26 14:15:15 volumio volumio[13923]: info: Loading plugin "webradio"... Jan 26 14:15:15 volumio volumio[13923]: info: Loading plugin "i2s_dacs"... Jan 26 14:15:15 volumio volumio[13923]: info: Loading plugin "volumiodiscovery"... Jan 26 14:15:15 volumio volumio[13923]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 14:15:15 volumio volumio[13923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:15:15 volumio node[13923]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 14:15:15 volumio volumio[13923]: *** WARNING *** For more information see Jan 26 14:15:15 volumio volumio[13923]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 14:15:15 volumio volumio[13923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:15:15 volumio volumio[13923]: *** WARNING *** For more information see Jan 26 14:15:15 volumio node[13923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:15:15 volumio node[13923]: *** WARNING *** For more information see Jan 26 14:15:15 volumio node[13923]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 14:15:15 volumio node[13923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 14:15:15 volumio node[13923]: *** WARNING *** For more information see Jan 26 14:15:15 volumio volumio[13923]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 14:15:15 volumio volumio[13923]: info: Discovery: Started advertising with name: Volumio Jan 26 14:15:16 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 14:15:16 volumio volumio[13923]: info: Loading plugin "spop"... Jan 26 14:15:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 26 14:15:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:16 volumio go-librespot[14005]: go-librespot daemon starting... Jan 26 14:15:16 volumio go-librespot[14006]: time="2026-01-26T14:15:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:16 volumio go-librespot[14006]: time="2026-01-26T14:15:16+07:00" level=debug msg="app state loaded" Jan 26 14:15:16 volumio go-librespot[14006]: time="2026-01-26T14:15:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=info msg="zeroconf server listening on port 46237" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="obtained new client token: AAA0l8ZO1QjeBjO5KgejvCPnf0+BKliSrl84uoLJj50qeBud+Oj+FAcbVCR02qgWZSZ/MLTI93htVUAod/rLOO4nwgPV7d5Spbpx1MdOiPsM8CRqTnyxAS6JGbxFr9kl947V2QmKENdp8qDhOOuQivbgw6Nex+NoscsELit6uLi4s+QMbefrJaU4WA74StegmVAgnjOyg3XiOgAshhy3E2TH5hGekBAcV6FBVKP1qIBDJc3vZGXWir+7LGU=" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15:17+07:00" level=debug msg="completed challenge" Jan 26 14:15:17 volumio go-librespot[14006]: time="2026-01-26T14:15: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 26 14:15:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:17 volumio volumio[13923]: info: Loading plugin "ytcr"... Jan 26 14:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:20 volumio volumio[13923]: info: Loading plugin "ytmusic"... Jan 26 14:15:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 26 14:15:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:20 volumio go-librespot[14014]: go-librespot daemon starting... Jan 26 14:15:20 volumio go-librespot[14015]: time="2026-01-26T14:15:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:20 volumio go-librespot[14015]: time="2026-01-26T14:15:20+07:00" level=debug msg="app state loaded" Jan 26 14:15:20 volumio go-librespot[14015]: time="2026-01-26T14:15:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:21 volumio volumio-remote-updater[628]: [2026-01-26 14:15:21] [connect] Successful connection Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=info msg="zeroconf server listening on port 39121" Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="obtained new client token: AABUPIwirxAx61LaoBYuzh1VIyRMPuG5NxDGukMvjK9kpQ6Mcsov2S3zP3fgQ54jhSsAdPh9cXRm+shAc2x/mNhLDbxuV7uqChKOsaXQhhU8/P/tyKMKavoCM5CIvEWTE1TQ/aLC8MkDjP8Vw6xJ6Evqi9t42w0h4ItnJYFHRfiufJcj1ZEWbFDKrTtiCmJhbQho+qCOK0AmUqJ4uyKx3zksB1EN4zePWQ7RFZ/XHbnUZWz48AdjqH29G7U=" Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "outputs"... Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "albumart"... Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:21 volumio volumio[13923]: info: Plugin example_plugin is not enabled Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "inputs"... Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "updater_comm"... Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15:21+07:00" level=debug msg="completed challenge" Jan 26 14:15:21 volumio volumio[13923]: info: Plugin mpdemulation is not enabled Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "rest_api"... Jan 26 14:15:21 volumio go-librespot[14015]: time="2026-01-26T14:15: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 26 14:15:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "websocket"... Jan 26 14:15:21 volumio volumio[13923]: info: Starting Socket.io Server version 1.7.4 Jan 26 14:15:21 volumio volumio[13923]: info: Loading plugin "RoonBridge"... Jan 26 14:15:22 volumio volumio[13923]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 14:15:22 volumio volumio[13923]: info: Loading i18n strings for locale en Jan 26 14:15:22 volumio volumio[13923]: Updating browse sources language Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::initPlayerControls Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 14:15:22 volumio volumio[13923]: Express server listening on port 3000 Jan 26 14:15:22 volumio volumio[13923]: [Metrics] WebUI: 15s 978.54ms Jan 26 14:15:22 volumio volumio[13923]: info: CoreStateMachine::resetVolumioState Jan 26 14:15:22 volumio volumio[13923]: info: CoreStateMachine::getcurrentVolume Jan 26 14:15:22 volumio volumio[13923]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 14:15:22 volumio volumio[14036]: Forking 3 albumart workers Jan 26 14:15:22 volumio sudo[14051]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 14:15:22 volumio sudo[14051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:22 volumio sudo[14051]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:22 volumio sudo[14055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 14:15:22 volumio volumio[13923]: info: Volumio Network Manager: Network status updated: 1 Jan 26 14:15:22 volumio sudo[14055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:23 volumio sudo[14055]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:23 volumio volumio-remote-updater[628]: [2026-01-26 14:15:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769411721 101 Jan 26 14:15:23 volumio volumio[13923]: 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 26 14:15:23 volumio volumio[13923]: info: VolumeController:: Volume=100 Mute =false Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::pushState Jan 26 14:15:23 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::volumioPushState Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::updateTrackBlock Jan 26 14:15:23 volumio volumio[13923]: info: CorePlayQueue::getTrackBlock Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:23 volumio volumio[13923]: info: Reloading queue from file Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::setRepeat null single undefined Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::pushState Jan 26 14:15:23 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::volumioPushState Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::setRandom null Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::pushState Jan 26 14:15:23 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::volumioPushState Jan 26 14:15:23 volumio volumio[13923]: info: Setting Device type: Raspberry PI Jan 26 14:15:23 volumio volumio[13923]: info: Completed loading Core Plugins Jan 26 14:15:23 volumio volumio[13923]: info: Preparing to generate the ALSA configuration file Jan 26 14:15:23 volumio volumio[13923]: info: VolumeController:: Volume=100 Mute =false Jan 26 14:15:23 volumio volumio[13923]: info: CoreStateMachine::pushState Jan 26 14:15:23 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::volumioPushState Jan 26 14:15:23 volumio sudo[14097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 14:15:23 volumio sudo[14097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:23 volumio volumio[13923]: info: Asound.conf file unchanged, so no further update is needed Jan 26 14:15:23 volumio volumio[13923]: info: Output device has changed, restarting MPD Jan 26 14:15:23 volumio sudo[14097]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:23 volumio volumio[13923]: info: Output device has changed, restarting Shairport Sync Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:23 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:23 volumio sudo[14100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 14:15:23 volumio sudo[14100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:23 volumio sudo[14100]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:23 volumio sudo[14102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 14:15:23 volumio sudo[14102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:23 volumio volumio[13923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 14:15:23 volumio volumio[13923]: info: ___________ START PLUGINS ___________ Jan 26 14:15:24 volumio volumio[13923]: info: ControllerMpd::onStart: Initializing MPD Jan 26 14:15:24 volumio volumio[13923]: info: Creating MPD Configuration file Jan 26 14:15:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:15:24 volumio volumio[13923]: info: [1769411724114] CoreMusicLibrary::Adding element Media Servers Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:15:24 volumio sudo[14112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 14:15:24 volumio sudo[14112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:24 volumio sudo[14110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 14:15:24 volumio sudo[14110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:24 volumio volumio[13923]: info: UPNP Browser: Client initialized successfully Jan 26 14:15:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 14:15:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 14:15:24 volumio systemd[1]: mpd.service: Consumed 7.380s CPU time. Jan 26 14:15:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 14:15:24 volumio sudo[14110]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 14:15:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:24 volumio volumio[13923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 14:15:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 14:15:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 14:15:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 14:15:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 14:15:24 volumio volumio[13923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 14:15:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 14:15:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:15:24 volumio volumio[13923]: info: [1769411724505] CoreMusicLibrary::Adding element Last_100 Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:15:24 volumio volumio[13923]: info: [1769411724516] CoreMusicLibrary::Adding element Webradio Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:15:24 volumio volumio[13923]: info: Initializing BBC Radios Jan 26 14:15:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 14:15:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:24 volumio volumio[13923]: info: Creating Spotify config file Jan 26 14:15:24 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 26 14:15:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:25 volumio go-librespot[14140]: go-librespot daemon starting... Jan 26 14:15:25 volumio sudo[14131]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 14:15:25 volumio sudo[14131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 14:15:25 volumio sudo[14131]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:25 volumio go-librespot[14141]: time="2026-01-26T14:15:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:25 volumio go-librespot[14141]: time="2026-01-26T14:15:25+07:00" level=info msg="zeroconf server listening on port 42469" Jan 26 14:15:26 volumio volumio[14052]: Starting albumart workers Jan 26 14:15:26 volumio volumio[13923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:15:26 volumio volumio[13923]: info: [1769411726173] CoreMusicLibrary::Adding element YouTube Music Jan 26 14:15:26 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:15:26 volumio volumio[13923]: Cannot find translation for source YouTube Music Jan 26 14:15:26 volumio volumio[13923]: info: Volumio Calling Home Jan 26 14:15:26 volumio sudo[14152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 14:15:26 volumio sudo[14152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:26 volumio volumio[14054]: Starting albumart workers Jan 26 14:15:26 volumio volumio[14056]: Starting albumart workers Jan 26 14:15:26 volumio sudo[14152]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:27 volumio volumio[13923]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 14:15:27 volumio volumio[13923]: info: Discovery: Found device Volumio Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::volumioGetState Jan 26 14:15:27 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:27 volumio volumio[13923]: info: MPD Permissions set Jan 26 14:15:27 volumio volumio[13923]: info: MPD Permissions set Jan 26 14:15:27 volumio volumio[13923]: info: Upmpdcli Daemon Started Jan 26 14:15:27 volumio volumio[13923]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 14:15:27 volumio volumio[13923]: info: Discovery: Found device Volumio Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::volumioGetState Jan 26 14:15:27 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:27 volumio volumio[13923]: info: Spotify config file written Jan 26 14:15:27 volumio sudo[14158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 14:15:27 volumio sudo[14158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:27 volumio volumio[13923]: 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 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:27 volumio go-librespot[14166]: go-librespot daemon starting... Jan 26 14:15:27 volumio sudo[14158]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 14:15:27 volumio volumio[13923]: info: No need to fix Spotify hosts Jan 26 14:15:27 volumio go-librespot[14171]: time="2026-01-26T14:15:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:27 volumio go-librespot[14171]: time="2026-01-26T14:15:27+07:00" level=debug msg="app state loaded" Jan 26 14:15:27 volumio go-librespot[14171]: time="2026-01-26T14:15:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:28 volumio go-librespot[14171]: time="2026-01-26T14:15:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:28 volumio go-librespot[14171]: time="2026-01-26T14:15:28+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 26 14:15:28 volumio go-librespot[14171]: time="2026-01-26T14:15:28+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 26 14:15:28 volumio go-librespot[14171]: time="2026-01-26T14:15:28+07:00" level=info msg="zeroconf server listening on port 41875" Jan 26 14:15:28 volumio volumio[13923]: info: Volumio called home Jan 26 14:15:28 volumio go-librespot[14171]: time="2026-01-26T14:15:28+07:00" level=debug msg="obtained new client token: AABP+S3kw6eXVlSVsCSlfh9r8EPJnMRqpuKcbigxTRrqw+mj2gmE+2pJYF6mDhF55z7uhUwez2X41hkGn2IUYbZuQH8MqbZMMbaPejV4sqj+/jNCuidYVCGUewjZC5mx7ohls0ZbVJ8q8jQQD2VkvI+zlBaUBYOtrBmkHA1GfTdCUTKoatUGdysfrClUEGVQuBXUFulpvth5d4yS1Lucd19JOfbgMsjYS2WIYpb0+redkIIMv1mrwGVUh1o=" Jan 26 14:15:29 volumio volumio[13923]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 14:15:29 volumio volumio[13923]: SPOTIFY: BQA_VHKgBnNYJFE-DxCeSFTYyCn_VmjQC68s2tqvNdI2TGTX-V8GbgcEhl3HUmwjhgt8w9oU9oJgNomtvCfT5lrJt-A78Ic2vLKNoD4wgdSYnx6vY8Kr0YQFIKwq0_i6FUtLLJ6fchK4CDruelXqyB_Ndd7s_Mrzpts4PZ-_g-5F361uk1mD4S0HMNXRrPot0iH4VnNQMzZyjddScqDaoEmA_Wz835bikFS5caxpgDAKZtf0msyC0wGJKl_s3KER6Bz3NezmOcjlKINzVrypjzwIBRA_hZxgmhTnnQPWYhcOhcyGY6f5jRL7 Jan 26 14:15:29 volumio volumio[13923]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 14:15:29 volumio volumio[13923]: info: New Spotify access token = BQA_VHKgBnNYJFE-DxCeSFTYyCn_VmjQC68s2tqvNdI2TGTX-V8GbgcEhl3HUmwjhgt8w9oU9oJgNomtvCfT5lrJt-A78Ic2vLKNoD4wgdSYnx6vY8Kr0YQFIKwq0_i6FUtLLJ6fchK4CDruelXqyB_Ndd7s_Mrzpts4PZ-_g-5F361uk1mD4S0HMNXRrPot0iH4VnNQMzZyjddScqDaoEmA_Wz835bikFS5caxpgDAKZtf0msyC0wGJKl_s3KER6Bz3NezmOcjlKINzVrypjzwIBRA_hZxgmhTnnQPWYhcOhcyGY6f5jRL7 Jan 26 14:15:29 volumio volumio[13923]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 14:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:29 volumio go-librespot[14171]: time="2026-01-26T14:15:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:29 volumio volumio[13923]: info: Starting Shairport Sync Jan 26 14:15:29 volumio volumio[13923]: info: Starting Shairport Sync Jan 26 14:15:29 volumio volumio[13923]: info: Starting Shairport Sync Jan 26 14:15:29 volumio go-librespot[14171]: time="2026-01-26T14:15:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:15:29 volumio sudo[14197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 14:15:29 volumio sudo[14197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:29 volumio sudo[14202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 14:15:29 volumio sudo[14202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:29 volumio sudo[14199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 14:15:29 volumio sudo[14199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 14:15:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 14:15:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 14:15:29 volumio systemd[1]: shairport-sync.service: Consumed 2.387s CPU time. Jan 26 14:15:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 14:15:29 volumio sudo[14197]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:29 volumio sudo[14199]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:29 volumio sudo[14202]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:29 volumio volumio[13923]: info: Shairport-Sync Started Jan 26 14:15:29 volumio volumio[13923]: Error adding Membership: Error: addMembership EINVAL Jan 26 14:15:29 volumio volumio[13923]: info: Shairport-Sync Started Jan 26 14:15:29 volumio volumio[13923]: info: Shairport-Sync Started Jan 26 14:15:29 volumio volumio[13923]: info: CoreCommandRouter::volumioGetState Jan 26 14:15:29 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:30 volumio volumio[13923]: 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 26 14:15:30 volumio volumio[13923]: info: Spotify Successfully logged in Jan 26 14:15:30 volumio volumio[13923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 14:15:30 volumio volumio[13923]: info: [1769411730054] CoreMusicLibrary::Adding element Spotify Jan 26 14:15:30 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 14:15:30 volumio volumio[13923]: Cannot find translation for source YouTube Music Jan 26 14:15:30 volumio volumio[13923]: Cannot find translation for source Spotify Jan 26 14:15:30 volumio volumio[13923]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 14:15:30 volumio volumio[13923]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 14:15:30 volumio volumio[13923]: info: VolumeController:: Volume=100 Mute =false Jan 26 14:15:30 volumio volumio[13923]: info: CoreCommandRouter::volumioGetState Jan 26 14:15:30 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:30 volumio volumio[13923]: info: CoreStateMachine::pushState Jan 26 14:15:30 volumio volumio[13923]: info: CorePlayQueue::getTrack 0 Jan 26 14:15:30 volumio volumio[13923]: info: CoreCommandRouter::volumioPushState Jan 26 14:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:32 volumio volumio[13923]: info: go-librespot daemon successfully initialized Jan 26 14:15:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 14:15:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:32 volumio go-librespot[14237]: go-librespot daemon starting... Jan 26 14:15:32 volumio mpd[14149]: 2026-01-26T14:15:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 14:15:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 14:15:32 volumio sudo[14112]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+07:00" level=debug msg="app state loaded" Jan 26 14:15:32 volumio sudo[14102]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:32 volumio volumio[13923]: error: MPD error: The expression evaluated to a falsy value: Jan 26 14:15:32 volumio volumio[13923]: assert.ok(self.idling) Jan 26 14:15:32 volumio volumio[13923]: error: The expression evaluated to a falsy value: Jan 26 14:15:32 volumio volumio[13923]: assert.ok(self.idling) Jan 26 14:15:32 volumio volumio[13923]: info: MPD running with PID14149 Jan 26 14:15:32 volumio volumio[13923]: ,establishing connection Jan 26 14:15:32 volumio volumio[13923]: error: updateQueue error: null Jan 26 14:15:32 volumio volumio[13923]: info: Completed starting Core Plugins Jan 26 14:15:32 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:32 volumio volumio[13923]: info: ----- MyVolumio plugins startup ---- Jan 26 14:15:32 volumio volumio[13923]: info: ------------------------------------------- Jan 26 14:15:32 volumio volumio[13923]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 14:15:32 volumio volumio[13923]: error: updateQueue error: null Jan 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+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 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+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 26 14:15:32 volumio go-librespot[14238]: time="2026-01-26T14:15:32+07:00" level=info msg="zeroconf server listening on port 42683" Jan 26 14:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:33 volumio go-librespot[14238]: time="2026-01-26T14:15:33+07:00" level=debug msg="obtained new client token: AADKqPsGSSXkPu3dZZ6ctX/7YOgWbhYvNOShtaZhvglYPUYUzbE3xtvKszHhaT+IcB1S1PIVPkO1Ajm5X3oH7lA1FTMICVHLYqdOw1NPtPpKIM9AYpM5PkAvQuStka7QEXltqqcppc09QZ/obY6sgyIA87xugayjvoEypDoDGNBRP/i3+wlCGsvf6BwBFy3rr059t1UE9oa0Y3YPnZIaPMFxdhdjSyv5I9o6PEBwa+BFkzEHk2q8bEOC" Jan 26 14:15:33 volumio go-librespot[14238]: time="2026-01-26T14:15:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:33 volumio go-librespot[14238]: time="2026-01-26T14:15:33+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:33 volumio go-librespot[14238]: time="2026-01-26T14:15:33+07:00" level=debug msg="completed challenge" Jan 26 14:15:33 volumio go-librespot[14238]: time="2026-01-26T14:15: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 26 14:15:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:35 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:35 volumio volumio[13923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 14:15:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:36 volumio go-librespot[14250]: go-librespot daemon starting... Jan 26 14:15:36 volumio go-librespot[14251]: time="2026-01-26T14:15:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:36 volumio go-librespot[14251]: time="2026-01-26T14:15:36+07:00" level=debug msg="app state loaded" Jan 26 14:15:36 volumio go-librespot[14251]: time="2026-01-26T14:15:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15: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 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15: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 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15: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 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15:37+07:00" level=info msg="zeroconf server listening on port 43125" Jan 26 14:15:37 volumio volumio[13923]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15:37+07:00" level=debug msg="obtained new client token: AAD5xc27Z821ynNFyUL4hZJtuEJUrMDYSFzMxIT5re85blRpg8fUukyQDyKLmhJ38lrVcO0Qibfc9zxqouN0bqzlR3pUCpzgnpyZM6gdH1h9HGXBS52S3u6HCcxwoGDbzWFYTW08qcA6VgAdXJD1mgk070K1BtnhMA2QqHStMCX8Enp+eCkJvpkzbCFVJVCvSRHDdM8fOT+Wsr4T12vRfsCvj9KqKdodWoj6cnCXMkKwH/+DPIn8uub3RD8=" Jan 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15:37+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15:37+07:00" level=debug msg="completed challenge" Jan 26 14:15:37 volumio go-librespot[14251]: time="2026-01-26T14:15:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 14:15:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:38 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:38 volumio volumio[13923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:41 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:41 volumio volumio[13923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 14:15:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:41 volumio go-librespot[14260]: go-librespot daemon starting... Jan 26 14:15:41 volumio go-librespot[14261]: time="2026-01-26T14:15:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:41 volumio go-librespot[14261]: time="2026-01-26T14:15:41+07:00" level=debug msg="app state loaded" Jan 26 14:15:41 volumio go-librespot[14261]: time="2026-01-26T14:15:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 14:15:41 volumio volumio[13923]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15: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-gew1.spotify.com:80]" Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+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 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+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 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+07:00" level=info msg="zeroconf server listening on port 36703" Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+07:00" level=debug msg="obtained new client token: AADULMnaXQjDsuLSZuXwi7LrFfdgiZqQZOXs/1F7sZJWeZAdcxcYg1U14yT/BXXkapNDH7Z2j/Ke1k2Fv178WAEZRYVy0UUhvmx/Kw6teCb8zeWHAP36xsktibvwuj8OCGC3KDnl7J8ItBQrBUw+MYNhiI7AsKk+dPkyt7WwLTPR+6WMKnBr2aH6NnMDLNsXDna0upRtwnUEhikRDFgdW8a4cIjEYuFkVd2B3tCZCQQFy2u8yDo4F+Qd" Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+07:00" level=debug msg="completed keyexchange" Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15:42+07:00" level=debug msg="completed challenge" Jan 26 14:15:42 volumio go-librespot[14261]: time="2026-01-26T14:15: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 26 14:15:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:43 volumio volumio[13923]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 14:15:43 volumio volumio[13923]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 14:15:43 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:43 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:43 volumio volumio[13923]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 14:15:43 volumio volumio[13923]: info: MyVolumio login type: Token Jan 26 14:15:43 volumio volumio[13923]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 14:15:43 volumio volumio[13923]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 14:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:45 volumio volumio[13923]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 14:15:45 volumio volumio[13923]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 14:15:45 volumio volumio[13923]: info: Streaming services startup Jan 26 14:15:45 volumio volumio[13923]: info: Starting Streaming Daemon Jan 26 14:15:45 volumio sudo[14283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 14:15:45 volumio sudo[14283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:45 volumio volumio[13923]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 14:15:45 volumio sudo[14283]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:45 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:45 volumio volumio[13923]: error: Cannot start Volumio Streaming Daemon Jan 26 14:15:45 volumio volumio[13923]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 14:15:45 volumio volumio[13923]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 14:15:45 volumio volumio[13923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 14:15:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:45 volumio go-librespot[14290]: go-librespot daemon starting... Jan 26 14:15:45 volumio go-librespot[14291]: time="2026-01-26T14:15:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:45 volumio go-librespot[14291]: time="2026-01-26T14:15:45+07:00" level=debug msg="app state loaded" Jan 26 14:15:45 volumio go-librespot[14291]: time="2026-01-26T14:15:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:46 volumio volumio[13923]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15:46+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 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15:46+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 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15:46+07:00" level=info msg="zeroconf server listening on port 38851" Jan 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15:46+07:00" level=debug msg="obtained new client token: AADf2mIhwjG2PmlZc65PtAk10cCx+crfOW61anQ2HoVROUbaOVFJM5dGZ/oeLCGggKaBiE2p9sxxrxq/0PGODHRXZ69Mn/S6za12QpSDqPa/PHKnrN0daum3+XXYe2WgCC63DoiKc7FNpG50o5egIyNGEYhiZtRvNbeTG2ddmp4GT2SoRXp6FEKsPkOFVkHDvIKgWwmBmbdsOCZ3fMLbsgK92ur4ZSKApRoud31jItM20e2C+MGlvCtoeaw=" Jan 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:46 volumio go-librespot[14291]: time="2026-01-26T14:15:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:15:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:47 volumio volumio[13923]: info: MyVolumio token set successfully Jan 26 14:15:47 volumio volumio[13923]: info: MYVOLUMIO: Adding device Jan 26 14:15:47 volumio volumio[13923]: info: MYVOLUMIO: Evaluating Server Jan 26 14:15:47 volumio volumio[13923]: info: MyVolumio status changed Jan 26 14:15:47 volumio volumio[13923]: info: Streaming services startup Jan 26 14:15:47 volumio volumio[13923]: info: Starting Streaming Daemon Jan 26 14:15:47 volumio volumio[13923]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 14:15:47 volumio volumio[13923]: info: Removing audio output: Jan 26 14:15:47 volumio volumio[13923]: info: Stoppping Tunnel 1 Jan 26 14:15:48 volumio sudo[14320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 14:15:48 volumio sudo[14320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:48 volumio sudo[14320]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:48 volumio sudo[14323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 26 14:15:48 volumio sudo[14323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:48 volumio volumio[13923]: error: Cannot start Volumio Streaming Daemon Jan 26 14:15:48 volumio volumio[13923]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 14:15:48 volumio volumio[13923]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 14:15:48 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 26 14:15:48 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 26 14:15:48 volumio volumio[13923]: info: Setting Geolocation for MyVolumio to as1 Jan 26 14:15:48 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:48 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:48 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:48 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 26 14:15:48 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 26 14:15:48 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 26 14:15:48 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 26 14:15:48 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 26 14:15:48 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 26 14:15:48 volumio sudo[14323]: pam_unix(sudo:session): session closed for user root Jan 26 14:15:48 volumio volumio[13923]: info: Remote SSH Stopped Jan 26 14:15:48 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:48 volumio volumio[13923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:48 volumio volumio[13923]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 14:15:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:49 volumio volumio[13923]: info: Updating MyVolumio device info Jan 26 14:15:49 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:49 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:49 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:49 volumio volumio[13923]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 14:15:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 14:15:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:50 volumio go-librespot[14325]: go-librespot daemon starting... Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=debug msg="app state loaded" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=info msg="zeroconf server listening on port 40363" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=debug msg="obtained new client token: AAD7KO7da1bJB0H8ZA9UGn1jseBhUuyST9F4phfFvpogVF/8nbIqfrtPpW2c3TYsy7jx524Q6S6dcal8Xq20YeDKlfkb5Je0yERw26i2RaQ3+o7r6hVpG0a2g0vtkmZh/kVmhc0YxGEhzDd+235eYdoqZ3BbqCkYXh7FkZzAy3NE3iqLApfEqiN8StNF7EMasmaJJfsaK1JnQr11WDIZOB0/+12vJ83c0ItcBWUkdf8g3Oi3vZNmPByi5iY=" Jan 26 14:15:50 volumio go-librespot[14326]: time="2026-01-26T14:15:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:51 volumio go-librespot[14326]: time="2026-01-26T14:15:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:15:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:51 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:51 volumio volumio[13923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:52 volumio volumio[13923]: info: MYVOLUMIO: Adding device Jan 26 14:15:52 volumio volumio[13923]: info: MYVOLUMIO: Evaluating Server Jan 26 14:15:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:53 volumio volumio[13923]: info: Setting Geolocation for MyVolumio to as1 Jan 26 14:15:53 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:53 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:53 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:53 volumio volumio[13923]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 14:15:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 14:15:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:54 volumio go-librespot[14366]: go-librespot daemon starting... Jan 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15:54+07:00" level=debug msg="app state loaded" Jan 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:54 volumio volumio[13923]: info: Initializing connection to go-librespot Websocket Jan 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15:54+07:00" level=debug msg="new websocket client" Jan 26 14:15:54 volumio volumio[13923]: info: Connection to go-librespot Websocket established Jan 26 14:15:54 volumio volumio[13923]: info: Updating MyVolumio device info Jan 26 14:15:54 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:54 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:54 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15: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 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15: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 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15: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 26 14:15:54 volumio go-librespot[14367]: time="2026-01-26T14:15:54+07:00" level=info msg="zeroconf server listening on port 44097" Jan 26 14:15:54 volumio volumio[13923]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 14:15:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:55 volumio go-librespot[14367]: time="2026-01-26T14:15:55+07:00" level=debug msg="obtained new client token: AACTiUXZmdXv0co9i5vTtORlrQOS3KzBM2ZaWTBVh40f1ZiEm9Q6L1TTx/9Ydmmr0/z03jMb0vrq5PvxMSGxdgYmBg8S7VxVwKgNRmU8S4f8ebB4oqdyQZCXjGoOHODjT36U8FlpW0YVMkZyucASRDA4pY3r1Cv60Xjoj/68LKvSdyD/wOUItUWe1ARwQ9fidOS2RbXSq+VKyUdf6f+39bgMGmf7XpXV0jmEHOhWvfCE7DmHeeDSx8NN" Jan 26 14:15:55 volumio go-librespot[14367]: time="2026-01-26T14:15:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 14:15:55 volumio go-librespot[14367]: time="2026-01-26T14:15:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 14:15:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 14:15:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 14:15:55 volumio volumio[13923]: info: Connection to go-librespot Websocket closed Jan 26 14:15:56 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 14:15:56 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 14:15:56 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 14:15:56 volumio volumio-remote-updater[628]: Test mode disabled Jan 26 14:15:56 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 26 14:15:56 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 26 14:15:56 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 26 14:15:56 volumio volumio[13923]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 26 14:15:56 volumio volumio[13923]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 26 14:15:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:57 volumio volumio[13923]: info: Getting Spotify volume Jan 26 14:15:57 volumio volumio[13923]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 14:15:57 volumio volumio[13923]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 14:15:57 volumio volumio[13923]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 14:15:57 volumio volumio[13923]: errno: -111, Jan 26 14:15:57 volumio volumio[13923]: code: 'ECONNREFUSED', Jan 26 14:15:57 volumio volumio[13923]: syscall: 'connect', Jan 26 14:15:57 volumio volumio[13923]: address: '127.0.0.1', Jan 26 14:15:57 volumio volumio[13923]: port: 9879, Jan 26 14:15:57 volumio volumio[13923]: response: undefined Jan 26 14:15:57 volumio volumio[13923]: } Jan 26 14:15:57 volumio volumio[13923]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 14:15:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 14:15:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 14:15:58 volumio go-librespot[14392]: go-librespot daemon starting... Jan 26 14:15:58 volumio go-librespot[14393]: time="2026-01-26T14:15:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 14:15:58 volumio go-librespot[14393]: time="2026-01-26T14:15:58+07:00" level=debug msg="app state loaded" Jan 26 14:15:58 volumio go-librespot[14393]: time="2026-01-26T14:15:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 14:15:59 volumio sudo[14402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 14:14' Jan 26 14:15:59 volumio sudo[14402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 14:15:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 14:15:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 14:15:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 14:15:59 volumio go-librespot[14393]: time="2026-01-26T14:15:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 14:15:59 volumio go-librespot[14393]: time="2026-01-26T14:15:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 14:15:59 volumio go-librespot[14393]: time="2026-01-26T14:15:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 14:15:59 volumio go-librespot[14393]: time="2026-01-26T14:15:59+07:00" level=info msg="zeroconf server listening on port 41307" Jan 26 14:15:59 volumio go-librespot[14393]: time="2026-01-26T14:15:59+07:00" level=debug msg="obtained new client token: AAD/gWRN1HS9CRSbl1fVaXtVHTdFOS4+Y79IavNSoYalTmbaJ8xcPZvT/Z1Ezd4xaMPLOkeyXrmRNU/CwC1YaMCXZMN1Yh+aARdOqtUwhA4vgwARvCEzToPNllg1hPYXOhQrwrlkA+82CRD03Pnopcitb6HBhVWE1K+IRCiNgmMHaYuPzj9pq8YFu1vGRBp8Y+Q6KyA599E7rXt0t42KK09NLWIvxg60hDZnslVC1oECO7SY5/CjJUJsEt4=" 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"