Jan 28 22:24:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 22:24:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:01 volumio go-librespot[4278]: go-librespot daemon starting... Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=debug msg="app state loaded" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:01 volumio volumio[3935]: info: Initializing connection to go-librespot Websocket Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=debug msg="new websocket client" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=info msg="zeroconf server listening on port 34719" Jan 28 22:24:01 volumio volumio[3935]: info: Connection to go-librespot Websocket established Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=debug msg="obtained new client token: AAAkuvftyT7oOxG9apYwePavCC9EGSIXnteWoZA2raAr1SCEeJaOUbTbsYC16O9MYjGLhgwnLPg3MsJ5iDlWQe/TEzHN+8SZVgN07AsFmznqTMlG7Zfy5kNlNy77p5ndXCWw9PxSWcQvRCQ9DFQrd7hMIHoNZza3JXfh2WCAGaMtUyPO4jJKdG5M8CBIHo7QUfemUGrUEFZ4/DbSvHWghTERCBOmapUxEcQdylCD2nxNkoxYnkzDc1A7jlc=" Jan 28 22:24:01 volumio go-librespot[4279]: time="2026-01-28T22:24:01+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 22:24:02 volumio go-librespot[4279]: time="2026-01-28T22:24:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 22:24:02 volumio volumio[3935]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 22:24:02 volumio go-librespot[4279]: time="2026-01-28T22:24:02+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 28 22:24:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:03 volumio volumio[3935]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 22:24:03 volumio volumio[3935]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 22:24:03 volumio volumio[3935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:03 volumio volumio[3935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:04 volumio volumio[3935]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 22:24:04 volumio volumio[3935]: info: MyVolumio login type: Token Jan 28 22:24:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:04 volumio volumio[3935]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 22:24:04 volumio volumio[3935]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 22:24:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 22:24:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:05 volumio go-librespot[4300]: go-librespot daemon starting... Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=debug msg="app state loaded" Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:05 volumio volumio[3935]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 22:24:05 volumio volumio[3935]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 22:24:05 volumio volumio[3935]: info: Streaming services startup Jan 28 22:24:05 volumio volumio[3935]: info: Starting Streaming Daemon Jan 28 22:24:05 volumio sudo[4309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:24:05 volumio sudo[4309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:05 volumio volumio[3935]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:05 volumio sudo[4309]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:05 volumio go-librespot[4301]: time="2026-01-28T22:24:05+07:00" level=info msg="zeroconf server listening on port 33983" Jan 28 22:24:05 volumio volumio[3935]: info: Getting Spotify volume Jan 28 22:24:05 volumio volumio[3935]: info: Connection to go-librespot Websocket closed Jan 28 22:24:05 volumio volumio[3935]: error: Cannot start Volumio Streaming Daemon Jan 28 22:24:05 volumio volumio[3935]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:24:05 volumio volumio[3935]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:24:06 volumio volumio[3935]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 22:24:06 volumio go-librespot[4301]: time="2026-01-28T22:24:06+07:00" level=debug msg="obtained new client token: AAAznVf91VKJrBbZt6f7sDEjal3LYjSB6RTCBGmZKWRDiedXQEM4XQ4q/5KCb898nfjrv+IepXpMA4Iv/zjrrh4qVnay9Ge/mv86j2umdeTudWQ2qN+1MkmVCFhEChd+wvOlAmxVGglb5QWizNn4XknOLyNCqJpIxto0VBnbunQhDKf2/RAjcn11QSAg/K8NHz8QrdJWUZyJvVq6KE6LAY2t/l82JRIAGW06zgSg+Qxs7E4nEXXP/LH/" Jan 28 22:24:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:06 volumio go-librespot[4301]: time="2026-01-28T22:24:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:06 volumio volumio[3935]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:06 volumio volumio[3935]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:06 volumio volumio[3935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 22:24:06 volumio volumio[3935]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 22:24:06 volumio volumio[3935]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 22:24:06 volumio volumio[3935]: info: Aligning Spotify Volume to Volumio Volume Jan 28 22:24:06 volumio volumio[3935]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:06 volumio volumio[3935]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:06 volumio volumio[3935]: info: Setting Spotify Volume from Volumio: 100 Jan 28 22:24:06 volumio go-librespot[4301]: time="2026-01-28T22:24:06+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 28 22:24:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:06 volumio volumio[3935]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:24:06 volumio volumio[3935]: Error: socket hang up Jan 28 22:24:06 volumio volumio[3935]: at connResetException (node:internal/errors:720:14) Jan 28 22:24:06 volumio volumio[3935]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 22:24:06 volumio volumio[3935]: at Socket.emit (node:events:526:35) Jan 28 22:24:06 volumio volumio[3935]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 22:24:06 volumio volumio[3935]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 22:24:06 volumio volumio[3935]: code: 'ECONNRESET', Jan 28 22:24:06 volumio volumio[3935]: response: undefined Jan 28 22:24:06 volumio volumio[3935]: } Jan 28 22:24:06 volumio volumio[3935]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:24:07 volumio sudo[4331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 22:23' Jan 28 22:24:07 volumio sudo[4331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:07 volumio sudo[4331]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:09 volumio volumio-remote-updater[628]: [2026-01-28 22:24:09] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 22:24:09 volumio volumio-remote-updater[628]: [2026-01-28 22:24:09] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 22:24:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 22:24:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:09 volumio go-librespot[4339]: go-librespot daemon starting... Jan 28 22:24:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 22:24:09 volumio systemd[1]: volumio.service: Consumed 1min 1.961s CPU time. Jan 28 22:24:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:24:09 volumio go-librespot[4341]: time="2026-01-28T22:24:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:09 volumio go-librespot[4341]: time="2026-01-28T22:24:09+07:00" level=debug msg="app state loaded" Jan 28 22:24:09 volumio go-librespot[4341]: time="2026-01-28T22:24:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:24:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10771. Jan 28 22:24:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:24:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 22:24:09 volumio systemd[1]: volumio.service: Consumed 1min 1.961s CPU time. Jan 28 22:24:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 22:24:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 22:24:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=info msg="zeroconf server listening on port 39801" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="obtained new client token: AAA/flPEuSRnq74aw3AOM+cM2kOLk1IVmjd903G72AV32i1O4OrWipNjsbPjUYu7nM4vpV7up0uDcfKLoQWlQn5PbjmsjxH83HEJ0A43rlblvx6hjMitJxSnRAGH6zK5q3QZaiaBTpc5YGSnZgcq6EPQeJN4em0lm1UATwtFHvAzERWEebZ66L01tHDut1RZmXh+PwdxnRTUu/73wlld7NMKIuGRB88mqpv7qBdDDxGDu6n/hq/iOcT2erE=" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=debug msg="completed challenge" Jan 28 22:24:10 volumio go-librespot[4341]: time="2026-01-28T22:24:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:13 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:13 volumio volumio[4355]: info: ----- Volumio3 ---- Jan 28 22:24:13 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:13 volumio volumio[4355]: info: ----- System startup ---- Jan 28 22:24:13 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 22:24:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:13 volumio go-librespot[4379]: go-librespot daemon starting... Jan 28 22:24:13 volumio go-librespot[4380]: time="2026-01-28T22:24:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:13 volumio go-librespot[4380]: time="2026-01-28T22:24:13+07:00" level=debug msg="app state loaded" Jan 28 22:24:13 volumio go-librespot[4380]: time="2026-01-28T22:24:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:14 volumio volumio-remote-updater[628]: [2026-01-28 22:24:14] [connect] Successful connection Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=info msg="zeroconf server listening on port 44741" Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="obtained new client token: AAAj803JEdmdvQzypMyRHpbxSiON8bsAZFyoEGTBAMOyxe+SsageYmJ8CVadX09t6BkVtr0vdbPxEWlyOnAQc35Hn33I3l+w1ajv0pMrHRAwfAMa1Szj3rcIt6DKQj5al10KeD1lnQqyh/3RaO7S4vwcQ7A1Y8O28VUS8ovKgjVo6rZmoqFGxM/Q6YHT6PHLEJYwcMJvlKydNvtgntu9DW9cdchwsmveKtC4vhup/d54LI6JwYcU9mwY+YU=" Jan 28 22:24:14 volumio volumio[4355]: info: MYVOLUMIO Environment detected Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 22:24:14 volumio volumio[4355]: info: Plugin folders cleanup Jan 28 22:24:14 volumio volumio[4355]: info: Scanning into folder /volumio/app/plugins/ Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category audio_interface Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category miscellanea Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category music_service Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category plugins.json Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category system_controller Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category user_interface Jan 28 22:24:14 volumio volumio[4355]: info: Scanning into folder /data/plugins/ Jan 28 22:24:14 volumio volumio[4355]: info: Scanning category music_service Jan 28 22:24:14 volumio volumio[4355]: info: Plugin folders cleanup completed Jan 28 22:24:14 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:14 volumio volumio[4355]: info: ----- Core plugins startup ---- Jan 28 22:24:14 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:14 volumio volumio[4355]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 22:24:14 volumio volumio[4355]: info: Adding plugin upnp to MyMusic Plugins Jan 28 22:24:14 volumio volumio[4355]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 22:24:14 volumio volumio[4355]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 22:24:14 volumio volumio[4355]: info: Loading plugins from folder /data/plugins/ Jan 28 22:24:14 volumio volumio[4355]: info: Loading plugin "system"... Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:14 volumio go-librespot[4380]: time="2026-01-28T22:24:14+07:00" level=debug msg="completed challenge" Jan 28 22:24:15 volumio volumio[4355]: info: Loading plugin "appearance"... Jan 28 22:24:15 volumio go-librespot[4380]: time="2026-01-28T22:24:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:16 volumio volumio[4355]: info: Loading plugin "network"... Jan 28 22:24:16 volumio volumio[4355]: info: Refreshing Cached IP Addresses Jan 28 22:24:16 volumio sudo[4394]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:24:17 volumio sudo[4394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:17 volumio sudo[4396]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:24:17 volumio sudo[4396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:17 volumio sudo[4394]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "services"... Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "alsa_controller"... Jan 28 22:24:17 volumio sudo[4396]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:17 volumio sudo[4403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 22:24:17 volumio sudo[4403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:17 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "wizard"... Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "networkfs"... Jan 28 22:24:17 volumio volumio[4355]: info: Starting Udev Watcher for removable devices Jan 28 22:24:17 volumio volumio[4355]: info: Ignoring mount for partition: boot Jan 28 22:24:17 volumio volumio[4355]: info: Ignoring mount for partition: volumio Jan 28 22:24:17 volumio volumio[4355]: info: Ignoring mount for partition: volumio_data Jan 28 22:24:17 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "volumio_command_line_client"... Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "upnp"... Jan 28 22:24:17 volumio volumio[4355]: info: [1769613857333] Starting Upmpd Daemon Jan 28 22:24:17 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "my_music"... Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "mpd"... Jan 28 22:24:17 volumio volumio[4355]: info: Loading plugin "upnp_browser"... Jan 28 22:24:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 22:24:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:18 volumio go-librespot[4427]: go-librespot daemon starting... Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=debug msg="app state loaded" Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:18 volumio go-librespot[4428]: time="2026-01-28T22:24:18+07:00" level=info msg="zeroconf server listening on port 38291" Jan 28 22:24:19 volumio go-librespot[4428]: time="2026-01-28T22:24:19+07:00" level=debug msg="obtained new client token: AAD2rPHKUCSDV+AqvU61GCCuLS980Xr+WRdSQGMu9Aw+uuTdltIFD/oEGQPXufN9D64bWsxk8PknrCJCH1T3Hn/RARCA61oZlehSqbLe4VKw3yfJVpXuf3jSIHKpUdiDkelJmU8zi5h+WBSeZ1ERNi2ecALmNI/dVwhWqsvO1ji+x3y6C/a5E3J/MQVziBWn5rIjWiYiIBkAmKyqWnSoMXtifIe66tAt6NJ25W1naOuPxH23hdHCKRtG" Jan 28 22:24:19 volumio go-librespot[4428]: time="2026-01-28T22:24:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:19 volumio go-librespot[4428]: time="2026-01-28T22:24:19+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:19 volumio go-librespot[4428]: time="2026-01-28T22:24:19+07:00" level=debug msg="completed challenge" Jan 28 22:24:19 volumio go-librespot[4428]: time="2026-01-28T22:24:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:19 volumio sudo[4403]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:20 volumio volumio[4355]: info: Starting UPNP Browser Jan 28 22:24:20 volumio volumio[4355]: info: Loading plugin "alarm-clock"... Jan 28 22:24:21 volumio volumio[4355]: info: Loading plugin "airplay_emulation"... Jan 28 22:24:21 volumio volumio[4355]: info: Starting Shairport Sync Jan 28 22:24:21 volumio volumio[4355]: info: Loading plugin "last_100"... Jan 28 22:24:21 volumio volumio[4355]: info: Loading plugin "webradio"... Jan 28 22:24:21 volumio volumio[4355]: info: Loading plugin "i2s_dacs"... Jan 28 22:24:21 volumio volumio[4355]: info: Loading plugin "volumiodiscovery"... Jan 28 22:24:21 volumio volumio[4355]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:24:21 volumio volumio[4355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:24:21 volumio node[4355]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:24:21 volumio volumio[4355]: *** WARNING *** For more information see Jan 28 22:24:21 volumio volumio[4355]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:24:21 volumio volumio[4355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:24:21 volumio volumio[4355]: *** WARNING *** For more information see Jan 28 22:24:21 volumio node[4355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:24:21 volumio node[4355]: *** WARNING *** For more information see Jan 28 22:24:21 volumio node[4355]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:24:21 volumio node[4355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:24:21 volumio node[4355]: *** WARNING *** For more information see Jan 28 22:24:21 volumio volumio[4355]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 22:24:21 volumio volumio[4355]: info: Discovery: Started advertising with name: Volumio Jan 28 22:24:21 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:24:21 volumio volumio[4355]: info: Loading plugin "spop"... Jan 28 22:24:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 22:24:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:22 volumio go-librespot[4437]: go-librespot daemon starting... Jan 28 22:24:22 volumio go-librespot[4438]: time="2026-01-28T22:24:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:22 volumio go-librespot[4438]: time="2026-01-28T22:24:22+07:00" level=debug msg="app state loaded" Jan 28 22:24:22 volumio go-librespot[4438]: time="2026-01-28T22:24:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+07:00" level=info msg="zeroconf server listening on port 36247" Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+07:00" level=debug msg="obtained new client token: AABAUoT5efKa+90RdsqIHfI7KXUkhqAGiiivmq3N/dNMUqvof85c5G6gBJaRjjANLFWIePtcNI51crTWP2wTZIi6rDnGDjGM5Ue6wjADa+MQpwJzbFpT8QQMYG+4ra1NJnOywo/q0tIFspC8mJv1dHMPiwzygkWdon1J9N660ait3AuY8EvwXUpv4pRTJq/OzC8kTJKCrsLVfOib4yGD8Fdea9H5TLIX0xOX7jw2fLo/kugE9cSAWS/GYu4=" Jan 28 22:24:23 volumio volumio[4355]: info: Loading plugin "ytcr"... Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:23 volumio go-librespot[4438]: time="2026-01-28T22:24:23+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 28 22:24:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:26 volumio volumio[4355]: info: Loading plugin "ytmusic"... Jan 28 22:24:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 22:24:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:26 volumio go-librespot[4445]: go-librespot daemon starting... Jan 28 22:24:26 volumio go-librespot[4446]: time="2026-01-28T22:24:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:26 volumio go-librespot[4446]: time="2026-01-28T22:24:26+07:00" level=debug msg="app state loaded" Jan 28 22:24:26 volumio go-librespot[4446]: time="2026-01-28T22:24:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:26 volumio volumio-remote-updater[628]: [2026-01-28 22:24:26] [connect] Successful connection Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "outputs"... Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "albumart"... Jan 28 22:24:27 volumio volumio[4355]: info: Plugin example_plugin is not enabled Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "inputs"... Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "updater_comm"... Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=info msg="zeroconf server listening on port 33985" Jan 28 22:24:27 volumio volumio[4355]: info: Plugin mpdemulation is not enabled Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "rest_api"... Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="obtained new client token: AABe/WG1HrUsQHSv5j1tlpReiYNC/h4NnBad58WZF9cenoY+RpZtJbun7X8pMHsQuSIQfSSZl+f/7UNQM5Gj6UTQx/sFY78TqMCz/dyVIeJDp77V+LIWJYZwvRaM1LjCBu/EfljQPoLJ85vU7y7hNQAZCxhPOXxF02DXfWILZ+I3WPnRlZS3wrZTAsWkMUFGbFkjudUNCvPbZi5WLzcu4R1+bua3csnVprE1O0236qobPaqSCrSmds480P0=" Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "websocket"... Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:27 volumio volumio[4355]: info: Starting Socket.io Server version 1.7.4 Jan 28 22:24:27 volumio volumio[4355]: info: Loading plugin "RoonBridge"... Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=debug msg="completed challenge" Jan 28 22:24:27 volumio go-librespot[4446]: time="2026-01-28T22:24:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:28 volumio volumio[4355]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 22:24:28 volumio volumio[4355]: info: Loading i18n strings for locale en Jan 28 22:24:28 volumio volumio[4355]: Updating browse sources language Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:24:28 volumio volumio[4468]: Forking 3 albumart workers Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::initPlayerControls Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:24:28 volumio volumio[4355]: Express server listening on port 3000 Jan 28 22:24:28 volumio volumio[4355]: [Metrics] WebUI: 16s 187.49ms Jan 28 22:24:28 volumio volumio[4355]: info: CoreStateMachine::resetVolumioState Jan 28 22:24:28 volumio volumio[4355]: info: CoreStateMachine::getcurrentVolume Jan 28 22:24:28 volumio volumio[4355]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:24:28 volumio sudo[4515]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:24:28 volumio sudo[4515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:28 volumio sudo[4515]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:28 volumio sudo[4513]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:24:28 volumio sudo[4513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:28 volumio sudo[4513]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:28 volumio volumio[4355]: info: Volumio Network Manager: Network status updated: 1 Jan 28 22:24:29 volumio volumio[4355]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::pushState Jan 28 22:24:29 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::volumioPushState Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::updateTrackBlock Jan 28 22:24:29 volumio volumio[4355]: info: CorePlayQueue::getTrackBlock Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:24:29 volumio volumio-remote-updater[628]: [2026-01-28 22:24:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769613866 101 Jan 28 22:24:29 volumio volumio[4355]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:29 volumio volumio[4355]: info: Reloading queue from file Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::setRepeat null single undefined Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::pushState Jan 28 22:24:29 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::volumioPushState Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::setRandom null Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::pushState Jan 28 22:24:29 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::volumioPushState Jan 28 22:24:29 volumio volumio[4355]: info: Setting Device type: Raspberry PI Jan 28 22:24:29 volumio volumio[4355]: info: Completed loading Core Plugins Jan 28 22:24:29 volumio volumio[4355]: info: Preparing to generate the ALSA configuration file Jan 28 22:24:29 volumio volumio[4355]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:24:29 volumio volumio[4355]: info: CoreStateMachine::pushState Jan 28 22:24:29 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::volumioPushState Jan 28 22:24:29 volumio volumio[4355]: info: Asound.conf file unchanged, so no further update is needed Jan 28 22:24:29 volumio volumio[4355]: info: Output device has changed, restarting MPD Jan 28 22:24:29 volumio volumio[4355]: info: Output device has changed, restarting Shairport Sync Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:29 volumio sudo[4529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 22:24:29 volumio sudo[4529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:29 volumio volumio[4355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:24:29 volumio volumio[4355]: info: ___________ START PLUGINS ___________ Jan 28 22:24:29 volumio sudo[4531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:24:29 volumio sudo[4531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:29 volumio sudo[4533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:24:29 volumio volumio[4355]: info: ControllerMpd::onStart: Initializing MPD Jan 28 22:24:29 volumio volumio[4355]: info: Creating MPD Configuration file Jan 28 22:24:29 volumio sudo[4533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:29 volumio sudo[4531]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:24:29 volumio volumio[4355]: info: [1769613869973] CoreMusicLibrary::Adding element Media Servers Jan 28 22:24:29 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:24:30 volumio sudo[4543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:24:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 22:24:30 volumio sudo[4543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:30 volumio sudo[4529]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:30 volumio volumio[4355]: info: UPNP Browser: Client initialized successfully Jan 28 22:24:30 volumio sudo[4544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:24:30 volumio sudo[4544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:30 volumio sudo[4543]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:24:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:24:30 volumio systemd[1]: mpd.service: Consumed 7.334s CPU time. Jan 28 22:24:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:24:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:24:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:24:30 volumio volumio[4355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:24:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:24:30 volumio volumio[4355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:24:30 volumio volumio[4355]: info: [1769613870348] CoreMusicLibrary::Adding element Last_100 Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:24:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:24:30 volumio volumio[4355]: info: [1769613870367] CoreMusicLibrary::Adding element Webradio Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:24:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:24:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:24:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:24:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:24:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:24:30 volumio volumio[4355]: info: Initializing BBC Radios Jan 28 22:24:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:30 volumio volumio[4355]: info: Creating Spotify config file Jan 28 22:24:30 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:30 volumio sudo[4558]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 22:24:30 volumio sudo[4558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 22:24:30 volumio sudo[4558]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 22:24:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:31 volumio go-librespot[4574]: go-librespot daemon starting... Jan 28 22:24:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:31 volumio go-librespot[4575]: time="2026-01-28T22:24:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:31 volumio volumio[4479]: Starting albumart workers Jan 28 22:24:31 volumio volumio[4480]: Starting albumart workers Jan 28 22:24:31 volumio go-librespot[4575]: time="2026-01-28T22:24:31+07:00" level=info msg="zeroconf server listening on port 46521" Jan 28 22:24:32 volumio volumio[4478]: Starting albumart workers Jan 28 22:24:32 volumio volumio[4355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:24:32 volumio volumio[4355]: info: [1769613872076] CoreMusicLibrary::Adding element YouTube Music Jan 28 22:24:32 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:24:32 volumio volumio[4355]: Cannot find translation for source YouTube Music Jan 28 22:24:32 volumio volumio[4355]: info: Volumio Calling Home Jan 28 22:24:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:32 volumio sudo[4583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 22:24:32 volumio sudo[4583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:32 volumio sudo[4583]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:32 volumio volumio[4355]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:24:32 volumio volumio[4355]: info: Discovery: Found device Volumio Jan 28 22:24:32 volumio volumio[4355]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:32 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:33 volumio volumio[4355]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:24:33 volumio volumio[4355]: info: Discovery: Found device Volumio Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:33 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:33 volumio volumio[4355]: info: MPD Permissions set Jan 28 22:24:33 volumio volumio[4355]: info: MPD Permissions set Jan 28 22:24:33 volumio volumio[4355]: info: Upmpdcli Daemon Started Jan 28 22:24:33 volumio volumio[4355]: info: Spotify config file written Jan 28 22:24:33 volumio sudo[4590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 22:24:33 volumio sudo[4590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:33 volumio volumio[4355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 22:24:33 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 22:24:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio go-librespot[4597]: go-librespot daemon starting... Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio sudo[4590]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:33 volumio go-librespot[4598]: time="2026-01-28T22:24:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:33 volumio go-librespot[4598]: time="2026-01-28T22:24:33+07:00" level=debug msg="app state loaded" Jan 28 22:24:33 volumio go-librespot[4598]: time="2026-01-28T22:24:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:24:33 volumio volumio[4355]: info: No need to fix Spotify hosts Jan 28 22:24:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24:34+07:00" level=info msg="zeroconf server listening on port 45909" Jan 28 22:24:34 volumio volumio[4355]: info: Volumio called home Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24:34+07:00" level=debug msg="obtained new client token: AAC9viIxPikULYIPWwPloxhX80m3iH/ccGp4nG8JTqnswc4Vbf9KRsqhT0wJOFKpSa4JhCvdcqASEKtDZs+3Vhh0K60xhBPJloUk1ZrI0NuF1zgcVYNd1XEpkFmGtOdO253vqQPdWSYa2+sxmbmEwR7vrv6GAUkqPNYw+NnN+W3097Di+ekKVXldoNNTIL2K7ZYGiIRIXliDK3kqmRsOB9OhukCDF6NPyN2/VMvenNbOH2POJfbkIz9oIpU=" Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:34 volumio go-librespot[4598]: time="2026-01-28T22:24:34+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 28 22:24:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:34 volumio volumio[4355]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:24:34 volumio volumio[4355]: SPOTIFY: BQCswxf9vuuaMIne5V4YBEv6tCKc0VDh_zVHQpLpjhtumvfVXRytI3Ot2TKxEBqwiZmo1V5HKaeWP8u-aN55lbaPHVMh3Pqxe89NmPBtgkSTQuwmsg4hl3n1BN2Vlw-AEUowrNfEoQK8JgVM3V7jhw5yyBZJB_FjKYh-JakDgBjAvBbPwmuOxPuc-gMCaPSw30_UQLzvRU96Rr6hHbRk4H46HCQIBT67d31FjLz5C40hh9l9G-iGPT-9dpYuHgeEaI7raQiiwHC9MDzXNj0-WerJNN-VYT5lnoaVcELBdOClHSppO0sShx6X Jan 28 22:24:34 volumio volumio[4355]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:24:34 volumio volumio[4355]: info: New Spotify access token = BQCswxf9vuuaMIne5V4YBEv6tCKc0VDh_zVHQpLpjhtumvfVXRytI3Ot2TKxEBqwiZmo1V5HKaeWP8u-aN55lbaPHVMh3Pqxe89NmPBtgkSTQuwmsg4hl3n1BN2Vlw-AEUowrNfEoQK8JgVM3V7jhw5yyBZJB_FjKYh-JakDgBjAvBbPwmuOxPuc-gMCaPSw30_UQLzvRU96Rr6hHbRk4H46HCQIBT67d31FjLz5C40hh9l9G-iGPT-9dpYuHgeEaI7raQiiwHC9MDzXNj0-WerJNN-VYT5lnoaVcELBdOClHSppO0sShx6X Jan 28 22:24:34 volumio volumio[4355]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 22:24:34 volumio volumio[4355]: info: Starting Shairport Sync Jan 28 22:24:34 volumio volumio[4355]: info: Starting Shairport Sync Jan 28 22:24:34 volumio volumio[4355]: info: Starting Shairport Sync Jan 28 22:24:34 volumio sudo[4630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:24:34 volumio sudo[4630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:35 volumio sudo[4634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:24:35 volumio sudo[4634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:35 volumio sudo[4632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:24:35 volumio sudo[4632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 22:24:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 22:24:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:24:35 volumio systemd[1]: shairport-sync.service: Consumed 2.349s CPU time. Jan 28 22:24:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:24:35 volumio sudo[4630]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 22:24:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 22:24:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:24:35 volumio volumio[4355]: info: Shairport-Sync Started Jan 28 22:24:35 volumio volumio[4355]: Error adding Membership: Error: addMembership EINVAL Jan 28 22:24:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:24:35 volumio sudo[4634]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:35 volumio sudo[4632]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:35 volumio volumio[4355]: info: Shairport-Sync Started Jan 28 22:24:35 volumio volumio[4355]: info: Shairport-Sync Started Jan 28 22:24:35 volumio volumio[4355]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:35 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:35 volumio volumio[4355]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 22:24:35 volumio volumio[4355]: info: Spotify Successfully logged in Jan 28 22:24:35 volumio volumio[4355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:24:35 volumio volumio[4355]: info: [1769613875775] CoreMusicLibrary::Adding element Spotify Jan 28 22:24:35 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:24:35 volumio volumio[4355]: Cannot find translation for source YouTube Music Jan 28 22:24:35 volumio volumio[4355]: Cannot find translation for source Spotify Jan 28 22:24:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:36 volumio volumio[4355]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 22:24:36 volumio volumio[4355]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:24:36 volumio volumio[4355]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:24:36 volumio volumio[4355]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:36 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:36 volumio volumio[4355]: info: CoreStateMachine::pushState Jan 28 22:24:36 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:36 volumio volumio[4355]: info: CoreCommandRouter::volumioPushState Jan 28 22:24:37 volumio volumio[4355]: info: go-librespot daemon successfully initialized Jan 28 22:24:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 22:24:38 volumio mpd[4573]: 2026-01-28T22:24:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 22:24:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:38 volumio go-librespot[4683]: go-librespot daemon starting... Jan 28 22:24:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 22:24:38 volumio sudo[4533]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:38 volumio sudo[4544]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=debug msg="app state loaded" Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:38 volumio volumio[4355]: error: MPD error: The expression evaluated to a falsy value: Jan 28 22:24:38 volumio volumio[4355]: assert.ok(self.idling) Jan 28 22:24:38 volumio volumio[4355]: error: The expression evaluated to a falsy value: Jan 28 22:24:38 volumio volumio[4355]: assert.ok(self.idling) Jan 28 22:24:38 volumio volumio[4355]: error: updateQueue error: null Jan 28 22:24:38 volumio volumio[4355]: info: Completed starting Core Plugins Jan 28 22:24:38 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:38 volumio volumio[4355]: info: ----- MyVolumio plugins startup ---- Jan 28 22:24:38 volumio volumio[4355]: info: ------------------------------------------- Jan 28 22:24:38 volumio volumio[4355]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 22:24:38 volumio volumio[4355]: info: MPD running with PID4573 Jan 28 22:24:38 volumio volumio[4355]: ,establishing connection Jan 28 22:24:38 volumio volumio[4355]: error: updateQueue error: null Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=info msg="zeroconf server listening on port 46129" Jan 28 22:24:38 volumio go-librespot[4684]: time="2026-01-28T22:24:38+07:00" level=debug msg="obtained new client token: AAAh4tW5JmpQJh3mhbtnkrudRZ2XSgaF/PzsmuHiq+qiMx7ceDXN317q2Se5ndpL5bFf9ABF9gerCu0HdMDSQkoeirKZpDitQMNbrhA5r2rU+4IROGNOTDsRTSWLULW3K1l2hPykfwftOmyxET4Wx3Q2HFApANaepFDSzwTpP2VMFkdBfaxqCkAvp5JqGXIM2bIpgAgI5cjiQb9ZMOR3Ehowv9+zl7rr+GEbzJ+lErYlHr/xieDeR4IgNyw=" Jan 28 22:24:39 volumio go-librespot[4684]: time="2026-01-28T22:24:39+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 22:24:39 volumio go-librespot[4684]: time="2026-01-28T22:24:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 22:24:39 volumio go-librespot[4684]: time="2026-01-28T22:24:39+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 28 22:24:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:40 volumio volumio[4355]: info: Initializing connection to go-librespot Websocket Jan 28 22:24:40 volumio volumio[4355]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:24:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 22:24:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:42 volumio go-librespot[4695]: go-librespot daemon starting... Jan 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24:42+07:00" level=debug msg="app state loaded" Jan 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24: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 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24: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 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24: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 28 22:24:42 volumio go-librespot[4696]: time="2026-01-28T22:24:42+07:00" level=info msg="zeroconf server listening on port 38343" Jan 28 22:24:43 volumio go-librespot[4696]: time="2026-01-28T22:24:43+07:00" level=debug msg="obtained new client token: AABIQ3/3nNhPbA5rOmRCWR7vgbl6c/EWfSIsFQ+3qqyj6l9ueDsv/9Icado3NjHIfD37wTACsW5AcogWnDvhavNAUzKYjH8DeKN6z6XLuUaP5i2vqC3pRPSCDxUibZJbbyfZCFFSVjTjstM8Ko2Ih9m3Cbpir7TKin5WlNz1lSZnzpZjnWVqrDGGR4bGwKhh0JHFWhHie5kGjsL/osAwfa0VgyeHBNzAcD75ULsP3dGRmj28EXrQhwKg" Jan 28 22:24:43 volumio go-librespot[4696]: time="2026-01-28T22:24:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:43 volumio volumio[4355]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 22:24:43 volumio go-librespot[4696]: time="2026-01-28T22:24:43+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:43 volumio go-librespot[4696]: time="2026-01-28T22:24:43+07:00" level=debug msg="completed challenge" Jan 28 22:24:43 volumio go-librespot[4696]: time="2026-01-28T22:24:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:43 volumio volumio[4355]: info: Initializing connection to go-librespot Websocket Jan 28 22:24:43 volumio volumio[4355]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:24:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 22:24:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:46 volumio go-librespot[4703]: go-librespot daemon starting... Jan 28 22:24:46 volumio go-librespot[4704]: time="2026-01-28T22:24:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:46 volumio go-librespot[4704]: time="2026-01-28T22:24:46+07:00" level=debug msg="app state loaded" Jan 28 22:24:46 volumio go-librespot[4704]: time="2026-01-28T22:24:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:46 volumio volumio[4355]: info: Initializing connection to go-librespot Websocket Jan 28 22:24:46 volumio go-librespot[4704]: time="2026-01-28T22:24:46+07:00" level=debug msg="new websocket client" Jan 28 22:24:46 volumio volumio[4355]: info: Connection to go-librespot Websocket established Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24: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-gew1.spotify.com:80]" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=info msg="zeroconf server listening on port 34467" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=debug msg="obtained new client token: AADLZYY2cjAuKtjWTjLryPItTjfhwBFSzjmvexfpIOH3NvUfxL+105Lxv9YLfDQsnqTx+839usqv/YTOQLh2b0zWc+2wy968721rFapiarj4QsF1XH/1IVT8+zxyW6kZOQB2FkC3pIkJMiq6MILQLk7fBBgZuuJ6NUVFWoNxv+cG8MDkahLAsFF61p8l+nv5ibF+wzhbcNdNYEnV5M0quZyZYYBK+EUhisoW4pVQbxnYxOvma1/JiLtC" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24:47+07:00" level=debug msg="completed challenge" Jan 28 22:24:47 volumio go-librespot[4704]: time="2026-01-28T22:24: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 28 22:24:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:47 volumio volumio[4355]: info: Connection to go-librespot Websocket closed Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 22:24:47 volumio volumio[4355]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 22:24:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:49 volumio volumio[4355]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 22:24:49 volumio volumio[4355]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 22:24:49 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:49 volumio volumio[4355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:24:49 volumio volumio[4355]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 22:24:49 volumio volumio[4355]: info: MyVolumio login type: Token Jan 28 22:24:49 volumio volumio[4355]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 22:24:49 volumio volumio[4355]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 22:24:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 22:24:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:50 volumio go-librespot[4726]: go-librespot daemon starting... Jan 28 22:24:50 volumio go-librespot[4727]: time="2026-01-28T22:24:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:50 volumio go-librespot[4727]: time="2026-01-28T22:24:50+07:00" level=debug msg="app state loaded" Jan 28 22:24:50 volumio go-librespot[4727]: time="2026-01-28T22:24:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:51 volumio volumio[4355]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 22:24:51 volumio volumio[4355]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 22:24:51 volumio volumio[4355]: info: Streaming services startup Jan 28 22:24:51 volumio volumio[4355]: info: Starting Streaming Daemon Jan 28 22:24:51 volumio sudo[4736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:24:51 volumio sudo[4736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24: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 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24: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 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24: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 28 22:24:51 volumio volumio[4355]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=info msg="zeroconf server listening on port 44065" Jan 28 22:24:51 volumio sudo[4736]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:51 volumio volumio[4355]: info: Getting Spotify volume Jan 28 22:24:51 volumio volumio[4355]: info: Initializing connection to go-librespot Websocket Jan 28 22:24:51 volumio volumio[4355]: error: Cannot start Volumio Streaming Daemon Jan 28 22:24:51 volumio volumio[4355]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:24:51 volumio volumio[4355]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=debug msg="new websocket client" Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=debug msg="obtained new client token: AABt1yjj6jIUlfZULBwR9L3QJs91YDzwn4xOmlYXnSZwaKeFwLMeKxv+ARETJ3VSC1UJrNGWZ4m/nmec1Nm4TREfcZRSO8dARDEBUHE8VH1U9K6aoJ7GvZeQL7RrLfkWdos3eXbnYcdAyHyeS5wpy6GH6cw3q3gBu7rb4v+0JbnVLB9ixhMcc8w9aLjIdOZ/tNSPyBcNlPgcptAHEx9wY352PVggMwb/hVUDJMq4+jLAgUxcfTMIGFGqnbA=" Jan 28 22:24:51 volumio volumio[4355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 22:24:51 volumio volumio[4355]: info: Connection to go-librespot Websocket established Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:51 volumio volumio[4355]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:51 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:51 volumio volumio[4355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 22:24:51 volumio volumio[4355]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 22:24:51 volumio volumio[4355]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 22:24:51 volumio volumio[4355]: info: Aligning Spotify Volume to Volumio Volume Jan 28 22:24:51 volumio volumio[4355]: info: CoreCommandRouter::volumioGetState Jan 28 22:24:51 volumio volumio[4355]: info: CorePlayQueue::getTrack 0 Jan 28 22:24:51 volumio volumio[4355]: info: Setting Spotify Volume from Volumio: 100 Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=debug msg="completed challenge" Jan 28 22:24:51 volumio go-librespot[4727]: time="2026-01-28T22:24:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:51 volumio volumio[4355]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:24:52 volumio volumio[4355]: Error: socket hang up Jan 28 22:24:52 volumio volumio[4355]: at connResetException (node:internal/errors:720:14) Jan 28 22:24:52 volumio volumio[4355]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 22:24:52 volumio volumio[4355]: at Socket.emit (node:events:526:35) Jan 28 22:24:52 volumio volumio[4355]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 22:24:52 volumio volumio[4355]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 22:24:52 volumio volumio[4355]: code: 'ECONNRESET', Jan 28 22:24:52 volumio volumio[4355]: response: undefined Jan 28 22:24:52 volumio volumio[4355]: } Jan 28 22:24:52 volumio volumio[4355]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:24:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:53 volumio sudo[4756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 22:23' Jan 28 22:24:53 volumio sudo[4756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:24:53 volumio sudo[4756]: pam_unix(sudo:session): session closed for user root Jan 28 22:24:53 volumio volumio-remote-updater[628]: [2026-01-28 22:24:53] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 22:24:53 volumio volumio-remote-updater[628]: [2026-01-28 22:24:53] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 22:24:53 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 22:24:54 volumio systemd[1]: volumio.service: Consumed 1min 1.858s CPU time. Jan 28 22:24:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:24:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:24:54 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10772. Jan 28 22:24:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 22:24:54 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 22:24:54 volumio systemd[1]: volumio.service: Consumed 1min 1.858s CPU time. Jan 28 22:24:54 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 22:24:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 22:24:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 22:24:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:55 volumio go-librespot[4789]: go-librespot daemon starting... Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=debug msg="app state loaded" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=info msg="zeroconf server listening on port 37605" Jan 28 22:24:55 volumio go-librespot[4790]: time="2026-01-28T22:24:55+07:00" level=debug msg="obtained new client token: AABT+m9LULFt2b3URWORnw9TDyqaFCfVDhFXx6iGjgcJBbwvYHQrluZdNI9HwCq1jo2+SsANhpfzONSJc3oy2yNFp04HDB2J1sdwIbOGsIvEmPiFwAt135JyYeC7TSr1lcvNuOfI+/AdZhodciMMj7O76uhEXV20Dx1XkVKv4RYUCxT4is722URq0Bmmnk555emoCLoERuE3250Ay8i0P9ZOF7V/kAGPpB/sPr/Q1X+Q0+hMjCMQ4EfuoGE=" Jan 28 22:24:56 volumio go-librespot[4790]: time="2026-01-28T22:24:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:24:56 volumio go-librespot[4790]: time="2026-01-28T22:24:56+07:00" level=debug msg="completed keyexchange" Jan 28 22:24:56 volumio go-librespot[4790]: time="2026-01-28T22:24:56+07:00" level=debug msg="completed challenge" Jan 28 22:24:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:56 volumio go-librespot[4790]: time="2026-01-28T22:24:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:24:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:24:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:24:57 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:24:57 volumio volumio[4774]: info: ----- Volumio3 ---- Jan 28 22:24:57 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:24:57 volumio volumio[4774]: info: ----- System startup ---- Jan 28 22:24:57 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:24:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:24:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:24:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:24:58 volumio volumio-remote-updater[628]: [2026-01-28 22:24:58] [connect] Successful connection Jan 28 22:24:59 volumio volumio[4774]: info: MYVOLUMIO Environment detected Jan 28 22:24:59 volumio volumio[4774]: info: Plugin folders cleanup Jan 28 22:24:59 volumio volumio[4774]: info: Scanning into folder /volumio/app/plugins/ Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category audio_interface Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category miscellanea Jan 28 22:24:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 22:24:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category music_service Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category plugins.json Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category system_controller Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category user_interface Jan 28 22:24:59 volumio volumio[4774]: info: Scanning into folder /data/plugins/ Jan 28 22:24:59 volumio volumio[4774]: info: Scanning category music_service Jan 28 22:24:59 volumio volumio[4774]: info: Plugin folders cleanup completed Jan 28 22:24:59 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:24:59 volumio volumio[4774]: info: ----- Core plugins startup ---- Jan 28 22:24:59 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:24:59 volumio volumio[4774]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 22:24:59 volumio volumio[4774]: info: Adding plugin upnp to MyMusic Plugins Jan 28 22:24:59 volumio volumio[4774]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 22:24:59 volumio volumio[4774]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 22:24:59 volumio volumio[4774]: info: Loading plugins from folder /data/plugins/ Jan 28 22:24:59 volumio volumio[4774]: info: Loading plugin "system"... Jan 28 22:24:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:24:59 volumio go-librespot[4807]: go-librespot daemon starting... Jan 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24:59+07:00" level=debug msg="app state loaded" Jan 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:24:59 volumio volumio[4774]: info: Loading plugin "appearance"... Jan 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24: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 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24: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 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24: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 28 22:24:59 volumio go-librespot[4808]: time="2026-01-28T22:24:59+07:00" level=info msg="zeroconf server listening on port 35935" Jan 28 22:25:00 volumio go-librespot[4808]: time="2026-01-28T22:25:00+07:00" level=debug msg="obtained new client token: AADb3lXEFbwD8AaXsgnwcmA4IrmW8lzME6stXp/JwBqjogYRhnn4jLHUuqMY76Oc3q8Vp4/Lhv7g5QlvSyGmBW9dxzAW6gC3zb3srXGbxd/n9MSSDj+I8Sg51xs8z3BDKfEutt+JArP4XedFePAXPyf2lODaXM2YINnRfAUPon0blvj8ZU44+gei7OyqXjXoB5e4+DLdFnlF/I3v3/opD9+gJ9IG8y4pi2z82MV+vnLVwxaWDKUwvwpU" Jan 28 22:25:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:00 volumio go-librespot[4808]: time="2026-01-28T22:25:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:00 volumio go-librespot[4808]: time="2026-01-28T22:25: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 28 22:25:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "network"... Jan 28 22:25:01 volumio volumio[4774]: info: Refreshing Cached IP Addresses Jan 28 22:25:01 volumio sudo[4819]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:25:01 volumio sudo[4819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:01 volumio sudo[4821]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:25:01 volumio sudo[4819]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:01 volumio sudo[4821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "services"... Jan 28 22:25:01 volumio sudo[4821]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "alsa_controller"... Jan 28 22:25:01 volumio sudo[4829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 22:25:01 volumio sudo[4829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:01 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "wizard"... Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "networkfs"... Jan 28 22:25:01 volumio volumio[4774]: info: Starting Udev Watcher for removable devices Jan 28 22:25:01 volumio volumio[4774]: info: Ignoring mount for partition: boot Jan 28 22:25:01 volumio volumio[4774]: info: Ignoring mount for partition: volumio Jan 28 22:25:01 volumio volumio[4774]: info: Ignoring mount for partition: volumio_data Jan 28 22:25:01 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "volumio_command_line_client"... Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "upnp"... Jan 28 22:25:01 volumio volumio[4774]: info: [1769613901741] Starting Upmpd Daemon Jan 28 22:25:01 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "my_music"... Jan 28 22:25:01 volumio volumio[4774]: info: Loading plugin "mpd"... Jan 28 22:25:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:02 volumio volumio[4774]: info: Loading plugin "upnp_browser"... Jan 28 22:25:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 22:25:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:03 volumio go-librespot[4852]: go-librespot daemon starting... Jan 28 22:25:03 volumio go-librespot[4853]: time="2026-01-28T22:25:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:03 volumio go-librespot[4853]: time="2026-01-28T22:25:03+07:00" level=debug msg="app state loaded" Jan 28 22:25:03 volumio go-librespot[4853]: time="2026-01-28T22:25:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=info msg="zeroconf server listening on port 39831" Jan 28 22:25:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:04 volumio sudo[4829]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=debug msg="obtained new client token: AACwi0O8ZZkvq4AoQWkaxwSoWndbmPiyGlLAtUDgkHVQI4SadfBEbxHXyShv41GwMKzOuxYHMuDpZu9tlSSb/udx+CIO7xx6aAwCvtLczeuQrcjhRmq5OdD2VT4PYRVFM8xgcDXAQSPRhO61DYg79eDV6wSG1MXbyQmzya1nxhCSU9+awFKKV2AGGLii+jlFCULV2Ry2vAgyN92Ox5TFRY/A6s5rfr1RcxWi86mKjl+OoKlmuecOqoVXFN0=" Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:04 volumio go-librespot[4853]: time="2026-01-28T22:25:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 22:25:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:05 volumio volumio[4774]: info: Starting UPNP Browser Jan 28 22:25:05 volumio volumio[4774]: info: Loading plugin "alarm-clock"... Jan 28 22:25:05 volumio volumio[4774]: info: Loading plugin "airplay_emulation"... Jan 28 22:25:05 volumio volumio[4774]: info: Starting Shairport Sync Jan 28 22:25:05 volumio volumio[4774]: info: Loading plugin "last_100"... Jan 28 22:25:05 volumio volumio[4774]: info: Loading plugin "webradio"... Jan 28 22:25:05 volumio volumio[4774]: info: Loading plugin "i2s_dacs"... Jan 28 22:25:05 volumio volumio[4774]: info: Loading plugin "volumiodiscovery"... Jan 28 22:25:05 volumio volumio[4774]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:25:05 volumio volumio[4774]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:25:05 volumio node[4774]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 22:25:05 volumio volumio[4774]: *** WARNING *** For more information see Jan 28 22:25:05 volumio volumio[4774]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:25:05 volumio volumio[4774]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:25:05 volumio volumio[4774]: *** WARNING *** For more information see Jan 28 22:25:05 volumio node[4774]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:25:05 volumio node[4774]: *** WARNING *** For more information see Jan 28 22:25:05 volumio node[4774]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 22:25:05 volumio node[4774]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 22:25:05 volumio node[4774]: *** WARNING *** For more information see Jan 28 22:25:05 volumio volumio[4774]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 22:25:05 volumio volumio[4774]: info: Discovery: Started advertising with name: Volumio Jan 28 22:25:06 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 22:25:06 volumio volumio[4774]: info: Loading plugin "spop"... Jan 28 22:25:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 22:25:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:07 volumio volumio[4774]: info: Loading plugin "ytcr"... Jan 28 22:25:07 volumio go-librespot[4862]: go-librespot daemon starting... Jan 28 22:25:07 volumio go-librespot[4863]: time="2026-01-28T22:25:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:07 volumio go-librespot[4863]: time="2026-01-28T22:25:07+07:00" level=debug msg="app state loaded" Jan 28 22:25:07 volumio go-librespot[4863]: time="2026-01-28T22:25:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=info msg="zeroconf server listening on port 43153" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="obtained new client token: AAAXNkiZJc/LeO/D06flMem3vl4wqiFhMI3XevjRxPFvZLAj2f/llVG0FODJFHgVmZ+QN4OUgUfZeFQKRLaoXMT1mTR0iTbGHJWoywonbLDjbflEeug8VnLqX3ZAR3caAnO/N0xWXKLmdGVagihk98rGc+UIhbwb8rXYsCddER3Xc1cqvgqs070tA7OxmvFIgxAjlFxAFrPFU30n58TxSh3sJiBoL4YV/CTEIaBLr57BgbEAHl/H/CYePNk=" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=debug msg="completed challenge" Jan 28 22:25:08 volumio go-librespot[4863]: time="2026-01-28T22:25:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:10 volumio volumio[4774]: info: Loading plugin "ytmusic"... Jan 28 22:25:11 volumio volumio-remote-updater[628]: [2026-01-28 22:25:11] [connect] Successful connection Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "outputs"... Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "albumart"... Jan 28 22:25:11 volumio volumio[4774]: info: Plugin example_plugin is not enabled Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "inputs"... Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "updater_comm"... Jan 28 22:25:11 volumio volumio[4774]: info: Plugin mpdemulation is not enabled Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "rest_api"... Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "websocket"... Jan 28 22:25:11 volumio volumio[4774]: info: Starting Socket.io Server version 1.7.4 Jan 28 22:25:11 volumio volumio[4774]: info: Loading plugin "RoonBridge"... Jan 28 22:25:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 22:25:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:12 volumio go-librespot[4896]: go-librespot daemon starting... Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=debug msg="app state loaded" Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:12 volumio volumio[4774]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 22:25:12 volumio volumio[4774]: info: Loading i18n strings for locale en Jan 28 22:25:12 volumio volumio[4774]: Updating browse sources language Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=info msg="zeroconf server listening on port 37983" Jan 28 22:25:12 volumio volumio[4886]: Forking 3 albumart workers Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::initPlayerControls Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:25:12 volumio volumio[4774]: Express server listening on port 3000 Jan 28 22:25:12 volumio volumio[4774]: [Metrics] WebUI: 16s 74.03ms Jan 28 22:25:12 volumio volumio[4774]: info: CoreStateMachine::resetVolumioState Jan 28 22:25:12 volumio volumio[4774]: info: CoreStateMachine::getcurrentVolume Jan 28 22:25:12 volumio volumio[4774]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:25:12 volumio go-librespot[4897]: time="2026-01-28T22:25:12+07:00" level=debug msg="obtained new client token: AABEMUJGFTU76t1pRlyiAEzZRPrvSM4eiY9o7Qy4Dk/4hTgM51Z+ueyyZIcDVAKzTm2182DKfk6r3p+hgRTSDBZnnzqvRrNAK8gurJe6kV6MAoVI/VYaNsNyiQ4xuzTwsaIeMptx9AMl35ElQrqKV/8fGCBLTCQ5w5QnXJohXV3IP977eNu4YktlWXyuW4NyfeSc7e+MF8T2al+uLwDFXhetR3VXqqehvUjEUwsxDMFG5JMaVR5rvCOK3wI=" Jan 28 22:25:13 volumio go-librespot[4897]: time="2026-01-28T22:25:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:13 volumio sudo[4939]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 22:25:13 volumio sudo[4939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:13 volumio go-librespot[4897]: time="2026-01-28T22:25:13+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:13 volumio go-librespot[4897]: time="2026-01-28T22:25:13+07:00" level=debug msg="completed challenge" Jan 28 22:25:13 volumio sudo[4939]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:13 volumio sudo[4941]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 22:25:13 volumio sudo[4941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:13 volumio sudo[4941]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:13 volumio go-librespot[4897]: time="2026-01-28T22:25: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 28 22:25:13 volumio volumio[4774]: info: Volumio Network Manager: Network status updated: 1 Jan 28 22:25:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:13 volumio volumio[4774]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:25:13 volumio volumio[4774]: info: CoreStateMachine::pushState Jan 28 22:25:13 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::volumioPushState Jan 28 22:25:13 volumio volumio[4774]: info: CoreStateMachine::updateTrackBlock Jan 28 22:25:13 volumio volumio[4774]: info: CorePlayQueue::getTrackBlock Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:25:13 volumio volumio-remote-updater[628]: [2026-01-28 22:25:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769613911 101 Jan 28 22:25:13 volumio volumio[4774]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:13 volumio volumio[4774]: info: Reloading queue from file Jan 28 22:25:13 volumio volumio[4774]: info: CoreStateMachine::setRepeat null single undefined Jan 28 22:25:13 volumio volumio[4774]: info: CoreStateMachine::pushState Jan 28 22:25:13 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::volumioPushState Jan 28 22:25:13 volumio volumio[4774]: info: CoreStateMachine::setRandom null Jan 28 22:25:13 volumio volumio[4774]: info: CoreStateMachine::pushState Jan 28 22:25:13 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:13 volumio volumio[4774]: info: CoreCommandRouter::volumioPushState Jan 28 22:25:13 volumio volumio[4774]: info: Setting Device type: Raspberry PI Jan 28 22:25:13 volumio volumio[4774]: info: Completed loading Core Plugins Jan 28 22:25:13 volumio volumio[4774]: info: Preparing to generate the ALSA configuration file Jan 28 22:25:14 volumio volumio[4774]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:25:14 volumio volumio[4774]: info: CoreStateMachine::pushState Jan 28 22:25:14 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::volumioPushState Jan 28 22:25:14 volumio volumio[4774]: info: Asound.conf file unchanged, so no further update is needed Jan 28 22:25:14 volumio volumio[4774]: info: Output device has changed, restarting MPD Jan 28 22:25:14 volumio sudo[4954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 22:25:14 volumio sudo[4954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:14 volumio volumio[4774]: info: Output device has changed, restarting Shairport Sync Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:14 volumio sudo[4960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:25:14 volumio sudo[4960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:14 volumio sudo[4954]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:14 volumio sudo[4957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:25:14 volumio volumio[4774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:25:14 volumio volumio[4774]: info: ___________ START PLUGINS ___________ Jan 28 22:25:14 volumio sudo[4957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:14 volumio sudo[4957]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:14 volumio volumio[4774]: info: ControllerMpd::onStart: Initializing MPD Jan 28 22:25:14 volumio volumio[4774]: info: Creating MPD Configuration file Jan 28 22:25:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:25:14 volumio volumio[4774]: info: [1769613914404] CoreMusicLibrary::Adding element Media Servers Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:25:14 volumio sudo[4967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 22:25:14 volumio sudo[4967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:14 volumio volumio[4774]: info: UPNP Browser: Client initialized successfully Jan 28 22:25:14 volumio sudo[4967]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:14 volumio sudo[4969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 22:25:14 volumio sudo[4969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:14 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:25:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:25:14 volumio systemd[1]: mpd.service: Consumed 7.330s CPU time. Jan 28 22:25:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:25:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:25:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:25:14 volumio volumio[4774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:25:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:25:14 volumio volumio[4774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:25:14 volumio volumio[4774]: info: [1769613914673] CoreMusicLibrary::Adding element Last_100 Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:25:14 volumio volumio[4774]: info: [1769613914693] CoreMusicLibrary::Adding element Webradio Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:25:14 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 22:25:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 22:25:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 22:25:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:25:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 22:25:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 22:25:14 volumio volumio[4774]: info: Initializing BBC Radios Jan 28 22:25:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:25:14 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:15 volumio volumio[4774]: info: Creating Spotify config file Jan 28 22:25:15 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:15 volumio sudo[4983]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 22:25:15 volumio sudo[4983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 22:25:15 volumio sudo[4983]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:15 volumio volumio[4904]: Starting albumart workers Jan 28 22:25:16 volumio volumio[4774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:25:16 volumio volumio[4774]: info: [1769613916086] CoreMusicLibrary::Adding element YouTube Music Jan 28 22:25:16 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:25:16 volumio volumio[4774]: Cannot find translation for source YouTube Music Jan 28 22:25:16 volumio volumio[4905]: Starting albumart workers Jan 28 22:25:16 volumio volumio[4774]: info: Volumio Calling Home Jan 28 22:25:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:16 volumio sudo[5000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 22:25:16 volumio sudo[5000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:16 volumio volumio[4906]: Starting albumart workers Jan 28 22:25:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 22:25:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:16 volumio go-librespot[5005]: go-librespot daemon starting... Jan 28 22:25:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:16 volumio sudo[5000]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:16 volumio go-librespot[5006]: time="2026-01-28T22:25:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:17 volumio volumio[4774]: info: MPD Permissions set Jan 28 22:25:17 volumio volumio[4774]: info: MPD Permissions set Jan 28 22:25:17 volumio volumio[4774]: info: Upmpdcli Daemon Started Jan 28 22:25:17 volumio volumio[4774]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:25:17 volumio volumio[4774]: info: Discovery: Found device Volumio Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::volumioGetState Jan 28 22:25:17 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:17 volumio volumio[4774]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 22:25:17 volumio volumio[4774]: info: Discovery: Found device Volumio Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::volumioGetState Jan 28 22:25:17 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:17 volumio go-librespot[5006]: time="2026-01-28T22:25:17+07:00" level=info msg="zeroconf server listening on port 36025" Jan 28 22:25:17 volumio volumio[4774]: info: Spotify config file written Jan 28 22:25:17 volumio sudo[5015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 22:25:17 volumio sudo[5015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 22:25:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 22:25:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:17 volumio go-librespot[5017]: go-librespot daemon starting... Jan 28 22:25:17 volumio volumio[4774]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 22:25:17 volumio sudo[5015]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio go-librespot[5018]: time="2026-01-28T22:25:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:17 volumio go-librespot[5018]: time="2026-01-28T22:25:17+07:00" level=debug msg="app state loaded" Jan 28 22:25:17 volumio go-librespot[5018]: time="2026-01-28T22:25:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:17 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:18 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:18 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 22:25:18 volumio volumio[4774]: info: No need to fix Spotify hosts Jan 28 22:25:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:18 volumio go-librespot[5018]: time="2026-01-28T22:25:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:18 volumio go-librespot[5018]: time="2026-01-28T22:25:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:18 volumio go-librespot[5018]: time="2026-01-28T22:25:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:18 volumio go-librespot[5018]: time="2026-01-28T22:25:18+07:00" level=info msg="zeroconf server listening on port 34547" Jan 28 22:25:18 volumio volumio[4774]: info: Volumio called home Jan 28 22:25:18 volumio go-librespot[5018]: time="2026-01-28T22:25:18+07:00" level=debug msg="obtained new client token: AAA1hRIIJ1ToI2R6RsydPN9+yZsysZsPZfwrwXz0AbbUc5yzJchq510Wlz97OPrPbOcVxpzqvjDrMBbUpgvJ6vifScKnZMB9hSgxhOg3kpejVNSAJiS0ddWyDt9VfS8qa5FixHx9ILB3fiQ5Ne6ItxbrMo1jNcVcCx3pP/kS04uowLlNHFf//CAuixwT5b9mnghp8+GRMWb+JOK8NrmRjD0N4Sks0Pz7GX5nvkgD+lE+o9rcKiW80LuVZCM=" Jan 28 22:25:19 volumio go-librespot[5018]: time="2026-01-28T22:25:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:19 volumio volumio[4774]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:25:19 volumio volumio[4774]: SPOTIFY: BQBrgirkvDIHzcs30778vwjlpAgAw5-pxqMTabtGubXKbny5RUrGO8jvnxnUXZQVkTef0nVxvEsopmZKZSUDI10ho1zmm8jNkboPBMIMxRerbl9Q3O8n-KxQ8y43nidAIyHZ9hfl95XK6uyGEoaUQBZOEvp-wPB5JMniJFD0yQypqCrDAemgtrYNfw5jXmxtPRAOS16QIsFl6nlZLSOGu7kgWuz5x8sSkZx8GJZ9BYiri7hY0gdBjFTb7PC5j54yhFFmdwxUPB_7-AR6Hy8iuVjCKOVXx2eOTg6Mo8FSqsR5iAdkKvjmkKZX Jan 28 22:25:19 volumio volumio[4774]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 22:25:19 volumio volumio[4774]: info: New Spotify access token = BQBrgirkvDIHzcs30778vwjlpAgAw5-pxqMTabtGubXKbny5RUrGO8jvnxnUXZQVkTef0nVxvEsopmZKZSUDI10ho1zmm8jNkboPBMIMxRerbl9Q3O8n-KxQ8y43nidAIyHZ9hfl95XK6uyGEoaUQBZOEvp-wPB5JMniJFD0yQypqCrDAemgtrYNfw5jXmxtPRAOS16QIsFl6nlZLSOGu7kgWuz5x8sSkZx8GJZ9BYiri7hY0gdBjFTb7PC5j54yhFFmdwxUPB_7-AR6Hy8iuVjCKOVXx2eOTg6Mo8FSqsR5iAdkKvjmkKZX Jan 28 22:25:19 volumio volumio[4774]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 22:25:19 volumio go-librespot[5018]: time="2026-01-28T22:25:19+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:19 volumio go-librespot[5018]: time="2026-01-28T22:25:19+07:00" level=debug msg="completed challenge" Jan 28 22:25:19 volumio go-librespot[5018]: time="2026-01-28T22:25:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:19 volumio volumio[4774]: info: Starting Shairport Sync Jan 28 22:25:19 volumio volumio[4774]: info: Starting Shairport Sync Jan 28 22:25:19 volumio volumio[4774]: info: Starting Shairport Sync Jan 28 22:25:19 volumio sudo[5055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:25:19 volumio sudo[5055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:19 volumio sudo[5059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:25:19 volumio sudo[5057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 22:25:19 volumio sudo[5057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:19 volumio sudo[5059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 22:25:19 volumio volumio[4774]: info: CoreCommandRouter::volumioGetState Jan 28 22:25:19 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 22:25:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:25:19 volumio systemd[1]: shairport-sync.service: Consumed 2.345s CPU time. Jan 28 22:25:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 22:25:19 volumio sudo[5059]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:19 volumio sudo[5057]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:19 volumio sudo[5055]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:19 volumio volumio[4774]: info: Shairport-Sync Started Jan 28 22:25:19 volumio volumio[4774]: Error adding Membership: Error: addMembership EINVAL Jan 28 22:25:19 volumio volumio[4774]: info: Shairport-Sync Started Jan 28 22:25:19 volumio volumio[4774]: info: Shairport-Sync Started Jan 28 22:25:19 volumio volumio[4774]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 22:25:19 volumio volumio[4774]: info: Spotify Successfully logged in Jan 28 22:25:20 volumio volumio[4774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 22:25:20 volumio volumio[4774]: info: [1769613920019] CoreMusicLibrary::Adding element Spotify Jan 28 22:25:20 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 22:25:20 volumio volumio[4774]: Cannot find translation for source YouTube Music Jan 28 22:25:20 volumio volumio[4774]: Cannot find translation for source Spotify Jan 28 22:25:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:20 volumio volumio[4774]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 22:25:20 volumio volumio[4774]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 22:25:21 volumio volumio[4774]: info: VolumeController:: Volume=100 Mute =false Jan 28 22:25:21 volumio volumio[4774]: info: CoreCommandRouter::volumioGetState Jan 28 22:25:21 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:21 volumio volumio[4774]: info: CoreStateMachine::pushState Jan 28 22:25:21 volumio volumio[4774]: info: CorePlayQueue::getTrack 0 Jan 28 22:25:21 volumio volumio[4774]: info: CoreCommandRouter::volumioPushState Jan 28 22:25:22 volumio volumio[4774]: info: go-librespot daemon successfully initialized Jan 28 22:25:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 22:25:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:22 volumio go-librespot[5096]: go-librespot daemon starting... Jan 28 22:25:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:22 volumio go-librespot[5097]: time="2026-01-28T22:25:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:22 volumio go-librespot[5097]: time="2026-01-28T22:25:22+07:00" level=debug msg="app state loaded" Jan 28 22:25:22 volumio go-librespot[5097]: time="2026-01-28T22:25:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:22 volumio mpd[4998]: 2026-01-28T22:25:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 22:25:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 22:25:22 volumio sudo[4960]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:22 volumio sudo[4969]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:22 volumio volumio[4774]: error: MPD error: The expression evaluated to a falsy value: Jan 28 22:25:22 volumio volumio[4774]: assert.ok(self.idling) Jan 28 22:25:22 volumio volumio[4774]: error: The expression evaluated to a falsy value: Jan 28 22:25:22 volumio volumio[4774]: assert.ok(self.idling) Jan 28 22:25:22 volumio volumio[4774]: error: updateQueue error: null Jan 28 22:25:22 volumio volumio[4774]: info: MPD running with PID4998 Jan 28 22:25:22 volumio volumio[4774]: ,establishing connection Jan 28 22:25:22 volumio go-librespot[5097]: time="2026-01-28T22:25:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:22 volumio go-librespot[5097]: time="2026-01-28T22:25:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:22 volumio go-librespot[5097]: time="2026-01-28T22:25:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:23 volumio go-librespot[5097]: time="2026-01-28T22:25:23+07:00" level=info msg="zeroconf server listening on port 32837" Jan 28 22:25:23 volumio volumio[4774]: info: Completed starting Core Plugins Jan 28 22:25:23 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:25:23 volumio volumio[4774]: info: ----- MyVolumio plugins startup ---- Jan 28 22:25:23 volumio volumio[4774]: info: ------------------------------------------- Jan 28 22:25:23 volumio volumio[4774]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 22:25:23 volumio volumio[4774]: error: updateQueue error: null Jan 28 22:25:23 volumio go-librespot[5097]: time="2026-01-28T22:25:23+07:00" level=debug msg="obtained new client token: AAAazGrfewapF+mxNN7vnBjkO2uhwnTB41V5HrJBZTMDPgOD4O0OTTnPVmfSu8B30/UQlZ+CBzo1dmQIuM0N6aLpgEdRQIjyb/9o6usUGV3nuepK1TDw5vS+ExJMK03al/gM+92QPlf+RPM3hKh7alYm/j7ROgaoE7bbwbrE9u+TslHAuhhDTkjPUuWIo285diIwPzX0Sp1BuHBAtpg8Tu0yG4ZMOKsyMcHgVoEZe8PxxwxUHQ8WWqMi" Jan 28 22:25:23 volumio go-librespot[5097]: time="2026-01-28T22:25:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:23 volumio go-librespot[5097]: time="2026-01-28T22:25:23+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:23 volumio go-librespot[5097]: time="2026-01-28T22:25:23+07:00" level=debug msg="completed challenge" Jan 28 22:25:23 volumio go-librespot[5097]: time="2026-01-28T22:25:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:25 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:25 volumio volumio[4774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 22:25:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:26 volumio go-librespot[5109]: go-librespot daemon starting... Jan 28 22:25:26 volumio go-librespot[5110]: time="2026-01-28T22:25:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:26 volumio go-librespot[5110]: time="2026-01-28T22:25:26+07:00" level=debug msg="app state loaded" Jan 28 22:25:26 volumio go-librespot[5110]: time="2026-01-28T22:25:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=info msg="zeroconf server listening on port 45403" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="obtained new client token: AAB7qOLLVZvqK0wmQ4bgzA+09JZjuEHZlX06v4MjsrC4jxLvS6zrowFkgcfLDWtyqAiVauavsdHWontJPvB78cpQeVSnYgRqzhAhyvkLzCM+NcM3ND3aNfAfHfHcnM2KMGrSB1/1gexJDnmHRvn8owimGr/Ja4HiPJDZ+bTd8uzSffppvvKz2FNGiWuPDlLs4sqeYcU1BMVf3buvUaGuvQXRreT5d3Bii2YQ0t7RavoAXstcIdGozr5pOmM=" Jan 28 22:25:27 volumio volumio[4774]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=debug msg="completed challenge" Jan 28 22:25:27 volumio go-librespot[5110]: time="2026-01-28T22:25:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:28 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:28 volumio volumio[4774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:31 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:31 volumio volumio[4774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 22:25:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:31 volumio go-librespot[5117]: go-librespot daemon starting... Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=debug msg="app state loaded" Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 22:25:31 volumio volumio[4774]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:31 volumio go-librespot[5118]: time="2026-01-28T22:25:31+07:00" level=info msg="zeroconf server listening on port 44127" Jan 28 22:25:32 volumio go-librespot[5118]: time="2026-01-28T22:25:32+07:00" level=debug msg="obtained new client token: AABq1ZlvsAbY4WoZM8jp8uf7pIXUB/JQCD9Xj8+gqAE6+jpWsjNBHAtfX7ZCTWMCh5QIpLy7tfxDvSyJ6pcT8LoQMEtqXqXGRhk7EsaAG2J90DLjDyzi3vzQVPgwyZg05Puej/e0TraEuX65rDN5EYIJfQbupSFsQbiE6W+siHeN9XPyuz3uCBVCUlYTtD01E/eEe6fJS3cAnTdU5/JrTlg1QjcrpQ5CHukh4O0qG8Zb1DqQPbaS2cxy" Jan 28 22:25:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:32 volumio go-librespot[5118]: time="2026-01-28T22:25:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:32 volumio go-librespot[5118]: time="2026-01-28T22:25:32+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:32 volumio go-librespot[5118]: time="2026-01-28T22:25:32+07:00" level=debug msg="completed challenge" Jan 28 22:25:32 volumio go-librespot[5118]: time="2026-01-28T22:25:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:33 volumio volumio[4774]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 22:25:33 volumio volumio[4774]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 22:25:33 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:33 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:33 volumio volumio[4774]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 22:25:33 volumio volumio[4774]: info: MyVolumio login type: Token Jan 28 22:25:33 volumio volumio[4774]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 22:25:33 volumio volumio[4774]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 22:25:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:35 volumio volumio[4774]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 22:25:35 volumio volumio[4774]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 22:25:35 volumio volumio[4774]: info: Streaming services startup Jan 28 22:25:35 volumio volumio[4774]: info: Starting Streaming Daemon Jan 28 22:25:35 volumio sudo[5140]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:25:35 volumio sudo[5140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:35 volumio volumio[4774]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 22:25:35 volumio sudo[5140]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:35 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:35 volumio volumio[4774]: error: Cannot start Volumio Streaming Daemon Jan 28 22:25:35 volumio volumio[4774]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:25:35 volumio volumio[4774]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:25:35 volumio volumio[4774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 22:25:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:35 volumio go-librespot[5146]: go-librespot daemon starting... Jan 28 22:25:35 volumio go-librespot[5147]: time="2026-01-28T22:25:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:35 volumio go-librespot[5147]: time="2026-01-28T22:25:35+07:00" level=debug msg="app state loaded" Jan 28 22:25:35 volumio go-librespot[5147]: time="2026-01-28T22:25:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:36 volumio volumio[4774]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=info msg="zeroconf server listening on port 35545" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="obtained new client token: AABEXSZ8KtWtRhyRMFx3PapsVErNgwdsr3hhVUI4V4K16+KzAFEAsOgNzb2OjotOYEdsBYYrEUQL11KTV6uP8nGtBD3ra9T7ODHk1Uc6M1sW9uFoes2QkwQFtVIu+ZnQ6Q5oL3f4NGntLlR8oYJXVXNxLc+eaC035+SA9aBofJFnG9/zAJm6G0/H0R1weINtETlfcdq72icjuXZ9NUgUl0m6E4uUBfMWinNerWuiIfeVKHXvsp0UnEuTVb4=" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=debug msg="completed challenge" Jan 28 22:25:36 volumio go-librespot[5147]: time="2026-01-28T22:25:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:37 volumio volumio[4774]: info: MyVolumio token set successfully Jan 28 22:25:37 volumio volumio[4774]: info: MYVOLUMIO: Adding device Jan 28 22:25:37 volumio volumio[4774]: info: MYVOLUMIO: Evaluating Server Jan 28 22:25:38 volumio volumio[4774]: info: MyVolumio status changed Jan 28 22:25:38 volumio volumio[4774]: info: Streaming services startup Jan 28 22:25:38 volumio volumio[4774]: info: Starting Streaming Daemon Jan 28 22:25:38 volumio volumio[4774]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 22:25:38 volumio volumio[4774]: info: Removing audio output: Jan 28 22:25:38 volumio volumio[4774]: info: Stoppping Tunnel 1 Jan 28 22:25:38 volumio sudo[5176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 22:25:38 volumio sudo[5176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:38 volumio sudo[5176]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:38 volumio volumio[4774]: error: Cannot start Volumio Streaming Daemon Jan 28 22:25:38 volumio volumio[4774]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 22:25:38 volumio volumio[4774]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 22:25:38 volumio sudo[5179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 22:25:38 volumio sudo[5179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:38 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:38 volumio volumio[4774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 22:25:38 volumio sudo[5179]: pam_unix(sudo:session): session closed for user root Jan 28 22:25:38 volumio volumio[4774]: info: Remote SSH Stopped Jan 28 22:25:38 volumio volumio[4774]: info: Setting Geolocation for MyVolumio to as1 Jan 28 22:25:38 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:38 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:38 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:39 volumio volumio[4774]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 22:25:39 volumio volumio[4774]: info: Updating MyVolumio device info Jan 28 22:25:39 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:39 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:39 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 22:25:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:40 volumio go-librespot[5182]: go-librespot daemon starting... Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=debug msg="app state loaded" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:40 volumio volumio[4774]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=info msg="zeroconf server listening on port 36039" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=debug msg="obtained new client token: AACzvx3ugyUWcOsUxca5Suflc3Ui88GNLhMak4r5Rz+b2aKaL1VNyo6q4NnlsxPZClUm+ItE/kB1yXm0mB7iimrPmHQMKcJpBi5ty1rEZBz0hlC9R28bUrbikEwUHPcgQVBaxrMWYtoCMRgtpBJ02H5uRzGQzsYU6YDD8hDgZFjyhTs30cJV5EjKXKhR/O2QrmFdLlsJr8C/embc4PRnHr0LCJ4wyQBAc1uYk0Jw9XyvF3m0E+carETGw+U=" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:40 volumio go-librespot[5183]: time="2026-01-28T22:25:40+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 28 22:25:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:41 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:41 volumio volumio[4774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:43 volumio volumio[4774]: info: MYVOLUMIO: Adding device Jan 28 22:25:43 volumio volumio[4774]: info: MYVOLUMIO: Evaluating Server Jan 28 22:25:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 22:25:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:44 volumio go-librespot[5223]: go-librespot daemon starting... Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="app state loaded" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:44 volumio volumio[4774]: info: Initializing connection to go-librespot Websocket Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="new websocket client" Jan 28 22:25:44 volumio volumio[4774]: info: Connection to go-librespot Websocket established Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=info msg="zeroconf server listening on port 35917" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="obtained new client token: AAAM/lAmJ9TA3lK6EIuATVhlV+pqi4VMVC+q/vMky0Zdhfla3kD6jmlCpEisiA1JkbcW5kr3d+UsX3hfbYglaG/fDM/kHU/FltDJFMBh/9L+Q92TfhsoW9KHalkISfK5/lLmLmFAZ2J3lMfTxQ0eaZznLT0IJTYuFnFqwnEuY9HQJo0T1r/go33RZaFdCoH+cwQzFl8NStDzwMEKjnN4/7pNfEQvWKvWl87x4JhKAqN9nw7rVDkSSA/H7Es=" Jan 28 22:25:44 volumio volumio[4774]: info: Setting Geolocation for MyVolumio to as1 Jan 28 22:25:44 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:44 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:44 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:44 volumio go-librespot[5224]: time="2026-01-28T22:25:44+07:00" level=debug msg="completed challenge" Jan 28 22:25:45 volumio go-librespot[5224]: time="2026-01-28T22:25:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 22:25:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 22:25:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 22:25:45 volumio volumio[4774]: info: Connection to go-librespot Websocket closed Jan 28 22:25:45 volumio volumio[4774]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 22:25:45 volumio volumio[4774]: info: Updating MyVolumio device info Jan 28 22:25:45 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:45 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:45 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:46 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 22:25:46 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 22:25:46 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 28 22:25:46 volumio volumio[4774]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 28 22:25:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:46 volumio volumio-remote-updater[628]: Test mode disabled Jan 28 22:25:46 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 28 22:25:46 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 28 22:25:46 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 28 22:25:46 volumio volumio[4774]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 28 22:25:46 volumio volumio[4774]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 28 22:25:47 volumio volumio[4774]: info: Getting Spotify volume Jan 28 22:25:47 volumio volumio[4774]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:25:47 volumio volumio[4774]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 22:25:47 volumio volumio[4774]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 22:25:47 volumio volumio[4774]: errno: -111, Jan 28 22:25:47 volumio volumio[4774]: code: 'ECONNREFUSED', Jan 28 22:25:47 volumio volumio[4774]: syscall: 'connect', Jan 28 22:25:47 volumio volumio[4774]: address: '127.0.0.1', Jan 28 22:25:47 volumio volumio[4774]: port: 9879, Jan 28 22:25:47 volumio volumio[4774]: response: undefined Jan 28 22:25:47 volumio volumio[4774]: } Jan 28 22:25:47 volumio volumio[4774]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 22:25:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 22:25:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 22:25:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 22:25:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 22:25:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 22:25:48 volumio go-librespot[5248]: go-librespot daemon starting... Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=debug msg="app state loaded" Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 22:25:48 volumio go-librespot[5249]: time="2026-01-28T22:25:48+07:00" level=info msg="zeroconf server listening on port 33093" Jan 28 22:25:48 volumio sudo[5258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 22:24' Jan 28 22:25:48 volumio sudo[5258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 22:25:49 volumio go-librespot[5249]: time="2026-01-28T22:25:49+07:00" level=debug msg="obtained new client token: AADqNg+jJFBASByVHIT+nePJK8+SeOUDxsRrmL62vhAZlHJGyeewP9wPaodKCV8+17qxeLkcxFxFSZUxOUdPVyJ2OEzOq6fGzUuz0WrccYF8GqylZbOj5Q4ywNiPaLjg5MjSQ9ZJDxy9oWnGV4CD+Jo60wiJtoiAZjbXm9JsHpsOhp2BPiCHQfh+KRCz6rFmba4Pys4JeDBEKlrvM82zjiF8jVbwdA/Jz9EMB80KNsY8Fcgn+6FiOpUV" Jan 28 22:25:49 volumio go-librespot[5249]: time="2026-01-28T22:25:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 22:25:49 volumio go-librespot[5249]: time="2026-01-28T22:25:49+07:00" level=debug msg="completed keyexchange" Jan 28 22:25:49 volumio go-librespot[5249]: time="2026-01-28T22:25:49+07:00" level=debug msg="completed challenge" 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"