Mar 28 22:23:00 volumio sudo[10993]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:00 volumio sudo[10993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:00 volumio sudo[10993]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:00 volumio sudo[10995]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:00 volumio sudo[10995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:00 volumio sudo[10995]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:00 volumio sudo[10998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 28 22:23:00 volumio sudo[10998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:00 volumio sudo[10998]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:00 volumio volumio[10720]: info: Upmpdcli Daemon Started Mar 28 22:23:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 28 22:23:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:00 volumio go-librespot[11001]: go-librespot daemon starting... Mar 28 22:23:00 volumio go-librespot[11002]: time="2026-03-28T22:23:00Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:00 volumio go-librespot[11002]: time="2026-03-28T22:23:00Z" level=debug msg="app state loaded" Mar 28 22:23:00 volumio go-librespot[11002]: time="2026-03-28T22:23:00Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=info msg="zeroconf server listening on port 44115" Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="obtained new client token: AABcezM3PwkXrYlcg0cmEFyqbjvhU7Bup4xb3tDh7p5AEqIs/34tiaX9FIkFd1EHCn9kTh581+CzEe6wrRYNyrm3WAoT2wM5G/HfrcvA6giOkPheUzNXP+U6eeTAdOmmYipqBz5Gxst0DsInQYUG0xjna3ZjLWhq1SXAjBP/NTogZaYDxBCg4bTA50ntl3GSCt+Pm7y+584GGO/Jc4o+/lkkQDtQDaXpbIvHwwdFyf5B6eDCCWaOovs=" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="completed keyexchange" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="completed challenge" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 22:23:01 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:01 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:01 volumio volumio[10720]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 22:23:01 volumio volumio[10720]: info: MyVolumio login type: Token Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 22:23:01 volumio volumio[10720]: info: Streaming services startup Mar 28 22:23:01 volumio volumio[10720]: info: Starting Streaming Daemon Mar 28 22:23:01 volumio sudo[11011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:01 volumio sudo[11011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:01 volumio volumio[10720]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 22:23:01 volumio sudo[11011]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:01 volumio volumio[10720]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:01 volumio volumio[10720]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:01 volumio volumio[10720]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:01 volumio volumio[10720]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="new websocket client" Mar 28 22:23:01 volumio volumio[10720]: info: Connection to go-librespot Websocket established Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="completed keyexchange" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=debug msg="completed challenge" Mar 28 22:23:01 volumio go-librespot[11002]: time="2026-03-28T22:23:01Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:02 volumio volumio[10720]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 28 22:23:02 volumio go-librespot[11002]: time="2026-03-28T22:23:02Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:02 volumio go-librespot[11002]: time="2026-03-28T22:23:02Z" level=debug msg="completed keyexchange" Mar 28 22:23:02 volumio go-librespot[11002]: time="2026-03-28T22:23:02Z" level=debug msg="completed challenge" Mar 28 22:23:02 volumio go-librespot[11002]: time="2026-03-28T22:23:02Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:02 volumio volumio[10720]: info: MyVolumio token set successfully Mar 28 22:23:02 volumio volumio[10720]: info: MYVOLUMIO: Adding device Mar 28 22:23:02 volumio volumio[10720]: info: MYVOLUMIO: Evaluating Server Mar 28 22:23:03 volumio volumio[10720]: info: MyVolumio status changed Mar 28 22:23:03 volumio volumio[10720]: info: Streaming services startup Mar 28 22:23:03 volumio volumio[10720]: info: Starting Streaming Daemon Mar 28 22:23:03 volumio volumio[10720]: info: Removing browser output: myVolumio user plan is not superstar Mar 28 22:23:03 volumio volumio[10720]: info: Removing audio output: Mar 28 22:23:03 volumio volumio[10720]: info: Stoppping Tunnel 1 Mar 28 22:23:03 volumio sudo[11038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:03 volumio sudo[11038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:03 volumio sudo[11040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 28 22:23:03 volumio sudo[11040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:03 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. Mar 28 22:23:03 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. Mar 28 22:23:03 volumio sudo[11038]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:03 volumio volumio[10720]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:03 volumio volumio[10720]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:03 volumio volumio[10720]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:03 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. Mar 28 22:23:03 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. Mar 28 22:23:03 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. Mar 28 22:23:03 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. Mar 28 22:23:03 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. Mar 28 22:23:03 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. Mar 28 22:23:03 volumio sudo[11040]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:03 volumio volumio[10720]: info: Remote SSH Stopped Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=debug msg="completed keyexchange" Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=debug msg="completed challenge" Mar 28 22:23:03 volumio volumio[10720]: info: Setting Geolocation for MyVolumio to eu12 Mar 28 22:23:03 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:03 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:03 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:03 volumio volumio[10720]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=debug msg="completed keyexchange" Mar 28 22:23:03 volumio go-librespot[11002]: time="2026-03-28T22:23:03Z" level=debug msg="completed challenge" Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:04 volumio volumio[10720]: info: Updating MyVolumio device info Mar 28 22:23:04 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:04 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:04 volumio volumio[10720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:04 volumio volumio[10720]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 28 22:23:04 volumio volumio[10720]: info: Getting Spotify volume Mar 28 22:23:04 volumio volumio[10720]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Mar 28 22:23:04 volumio volumio[10720]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:04 volumio volumio[10720]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:04 volumio volumio[10720]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 28 22:23:04 volumio volumio[10720]: SPOTIFY: SPOTIFY VOLUME undefined Mar 28 22:23:04 volumio volumio[10720]: SPOTIFY: VOLUMIO VOLUME 0 Mar 28 22:23:04 volumio volumio[10720]: info: Aligning Spotify Volume to Volumio Volume Mar 28 22:23:04 volumio volumio[10720]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:04 volumio volumio[10720]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:04 volumio volumio[10720]: info: Setting Spotify Volume from Volumio: 0 Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=debug msg="completed keyexchange" Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=debug msg="completed challenge" Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:04 volumio go-librespot[11002]: time="2026-03-28T22:23:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:04 volumio volumio[10720]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:04 volumio volumio[10720]: Error: socket hang up Mar 28 22:23:04 volumio volumio[10720]: at connResetException (node:internal/errors:720:14) Mar 28 22:23:04 volumio volumio[10720]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 28 22:23:04 volumio volumio[10720]: at Socket.emit (node:events:526:35) Mar 28 22:23:04 volumio volumio[10720]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 28 22:23:04 volumio volumio[10720]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 28 22:23:04 volumio volumio[10720]: code: 'ECONNRESET', Mar 28 22:23:04 volumio volumio[10720]: response: undefined Mar 28 22:23:04 volumio volumio[10720]: } Mar 28 22:23:04 volumio volumio[10720]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:05 volumio sudo[11057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:22' Mar 28 22:23:05 volumio sudo[11057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:05 volumio sudo[11057]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:05 volumio volumio-remote-updater[945]: [2026-03-28 22:23:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 28 22:23:05 volumio volumio-remote-updater[945]: [2026-03-28 22:23:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 28 22:23:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 28 22:23:05 volumio systemd[1]: volumio.service: Consumed 8.982s CPU time. Mar 28 22:23:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 87501. Mar 28 22:23:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 28 22:23:05 volumio systemd[1]: volumio.service: Consumed 8.982s CPU time. Mar 28 22:23:05 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 28 22:23:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:05 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:05 volumio volumio[11074]: info: ----- Volumio3 ---- Mar 28 22:23:05 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:05 volumio volumio[11074]: info: ----- System startup ---- Mar 28 22:23:05 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:06 volumio volumio[11074]: info: MYVOLUMIO Environment detected Mar 28 22:23:06 volumio volumio[11074]: info: Plugin folders cleanup Mar 28 22:23:06 volumio volumio[11074]: info: Scanning into folder /volumio/app/plugins/ Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category audio_interface Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category miscellanea Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category music_service Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category plugins.json Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category system_controller Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category user_interface Mar 28 22:23:06 volumio volumio[11074]: info: Scanning into folder /data/plugins/ Mar 28 22:23:06 volumio volumio[11074]: info: Scanning category music_service Mar 28 22:23:06 volumio volumio[11074]: info: Plugin folders cleanup completed Mar 28 22:23:06 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:06 volumio volumio[11074]: info: ----- Core plugins startup ---- Mar 28 22:23:06 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugins from folder /volumio/app/plugins/ Mar 28 22:23:06 volumio volumio[11074]: info: Adding plugin upnp to MyMusic Plugins Mar 28 22:23:06 volumio volumio[11074]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 28 22:23:06 volumio volumio[11074]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugins from folder /data/plugins/ Mar 28 22:23:06 volumio volumio[11074]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "system"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "appearance"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "network"... Mar 28 22:23:06 volumio volumio[11074]: info: Refreshing Cached IP Addresses Mar 28 22:23:06 volumio sudo[11102]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:06 volumio sudo[11102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:06 volumio sudo[11104]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:06 volumio sudo[11104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:06 volumio sudo[11102]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:06 volumio sudo[11104]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "services"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "alsa_controller"... Mar 28 22:23:06 volumio sudo[11113]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 28 22:23:06 volumio sudo[11113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:06 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "wizard"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "networkfs"... Mar 28 22:23:06 volumio volumio[11074]: info: Starting Udev Watcher for removable devices Mar 28 22:23:06 volumio volumio[11074]: info: Mounting Device 0ACB-A1DE Mar 28 22:23:06 volumio sudo[11141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:06 volumio sudo[11141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:06 volumio sudo[11141]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:06 volumio volumio[11074]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:06 volumio volumio[11074]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:06 volumio volumio[11074]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:06 volumio volumio[11074]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:06 volumio volumio[11074]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:06 volumio volumio[11074]: info: Ignoring mount for partition: boot Mar 28 22:23:06 volumio volumio[11074]: info: Ignoring mount for partition: volumio Mar 28 22:23:06 volumio volumio[11074]: info: Ignoring mount for partition: volumio_data Mar 28 22:23:06 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "volumio_command_line_client"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "upnp"... Mar 28 22:23:06 volumio volumio[11074]: info: [1774736586635] Starting Upmpd Daemon Mar 28 22:23:06 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "my_music"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "mpd"... Mar 28 22:23:06 volumio volumio[11074]: info: Loading plugin "upnp_browser"... Mar 28 22:23:07 volumio volumio[11074]: info: Starting UPNP Browser Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "alarm-clock"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "airplay_emulation"... Mar 28 22:23:07 volumio volumio[11074]: info: Starting Shairport Sync Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "last_100"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "webradio"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "i2s_dacs"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "volumiodiscovery"... Mar 28 22:23:07 volumio volumio[11074]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:07 volumio volumio[11074]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:07 volumio volumio[11074]: *** WARNING *** For more information see Mar 28 22:23:07 volumio volumio[11074]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:07 volumio volumio[11074]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:07 volumio volumio[11074]: *** WARNING *** For more information see Mar 28 22:23:07 volumio node[11074]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:07 volumio node[11074]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:07 volumio node[11074]: *** WARNING *** For more information see Mar 28 22:23:07 volumio node[11074]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:07 volumio node[11074]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:07 volumio node[11074]: *** WARNING *** For more information see Mar 28 22:23:07 volumio volumio[11074]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 28 22:23:07 volumio volumio[11074]: info: Discovery: Started advertising with name: Volumio Mar 28 22:23:07 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "spop"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "ytmusic"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "outputs"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "albumart"... Mar 28 22:23:07 volumio volumio[11074]: info: Plugin example_plugin is not enabled Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "inputs"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "updater_comm"... Mar 28 22:23:07 volumio volumio[11074]: info: Plugin mpdemulation is not enabled Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "rest_api"... Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "websocket"... Mar 28 22:23:07 volumio volumio[11074]: info: Starting Socket.io Server version 1.7.4 Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "podcast"... Mar 28 22:23:07 volumio volumio[11074]: info: ControllerPodcast::constructor Mar 28 22:23:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 28 22:23:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:07 volumio volumio[11074]: info: Loading plugin "rtlsdr_radio"... Mar 28 22:23:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:07 volumio go-librespot[11155]: go-librespot daemon starting... Mar 28 22:23:07 volumio volumio[11145]: Forking 3 albumart workers Mar 28 22:23:07 volumio go-librespot[11156]: time="2026-03-28T22:23:07Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:07 volumio go-librespot[11156]: time="2026-03-28T22:23:07Z" level=debug msg="app state loaded" Mar 28 22:23:07 volumio go-librespot[11156]: time="2026-03-28T22:23:07Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:08 volumio volumio[11074]: info: Loading i18n strings for locale en Mar 28 22:23:08 volumio volumio[11074]: Updating browse sources language Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::initPlayerControls Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: Express server listening on port 3000 Mar 28 22:23:08 volumio volumio[11074]: [Metrics] WebUI: 2s 328.30ms Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::resetVolumioState Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::getcurrentVolume Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:08 volumio volumio[11074]: info: Volumio Network Manager: Network status updated: 2 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: Reloading queue from file Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::setRepeat null single undefined Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::pushState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::setRandom true Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::pushState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:08 volumio volumio[11074]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::pushState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::updateTrackBlock Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrackBlock Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:08 volumio volumio[11074]: info: Setting Device type: Raspberry PI Mar 28 22:23:08 volumio volumio[11074]: info: Completed loading Core Plugins Mar 28 22:23:08 volumio volumio[11074]: info: Preparing to generate the ALSA configuration file Mar 28 22:23:08 volumio volumio[11074]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 28 22:23:08 volumio volumio[11074]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 28 22:23:08 volumio volumio[11074]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 28 22:23:08 volumio go-librespot[11156]: time="2026-03-28T22:23:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:08 volumio go-librespot[11156]: time="2026-03-28T22:23:08Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:08 volumio go-librespot[11156]: time="2026-03-28T22:23:08Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:08 volumio volumio[11163]: Starting albumart workers Mar 28 22:23:08 volumio go-librespot[11156]: time="2026-03-28T22:23:08Z" level=info msg="zeroconf server listening on port 38511" Mar 28 22:23:08 volumio volumio[11074]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:08 volumio volumio[11074]: info: CoreStateMachine::pushState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:08 volumio volumio[11162]: Starting albumart workers Mar 28 22:23:08 volumio volumio[11164]: Starting albumart workers Mar 28 22:23:08 volumio volumio[11074]: info: Asound.conf file unchanged, so no further update is needed Mar 28 22:23:08 volumio volumio[11074]: info: Output device has changed, restarting MPD Mar 28 22:23:08 volumio volumio[11074]: info: Output device has changed, restarting Shairport Sync Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio sudo[11211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:08 volumio sudo[11211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio sudo[11211]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:08 volumio volumio[11074]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:08 volumio volumio[11074]: info: ___________ START PLUGINS ___________ Mar 28 22:23:08 volumio sudo[11215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:08 volumio sudo[11215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio volumio[11074]: info: ControllerMpd::onStart: Initializing MPD Mar 28 22:23:08 volumio volumio[11074]: info: Creating MPD Configuration file Mar 28 22:23:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:08 volumio volumio[11074]: info: [1774736588447] CoreMusicLibrary::Adding element Media Servers Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio sudo[11221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:08 volumio sudo[11221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio sudo[11221]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:08 volumio volumio[11074]: info: UPNP Browser: Client initialized successfully Mar 28 22:23:08 volumio sudo[11223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:08 volumio sudo[11223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:08 volumio volumio[11074]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:08 volumio volumio[11074]: info: [1774736588525] CoreMusicLibrary::Adding element Last_100 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:08 volumio volumio[11074]: info: [1774736588526] CoreMusicLibrary::Adding element Webradio Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:08 volumio volumio[11074]: info: Initializing BBC Radios Mar 28 22:23:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: Creating Spotify config file Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio sudo[11238]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:23:08 volumio sudo[11238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:23:08 volumio sudo[11238]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:08 volumio go-librespot[11156]: time="2026-03-28T22:23:08Z" level=debug msg="obtained new client token: AABmw6l8MAwww5x5BZG+O259YyR1LH6SsM6pElDjUleBFPfvUJa1IGiRYQneXBO3h5XQ0lq7ITt/8967D/eLYcnqzjWLG5CXultdBkQmMVGoBq8no4wBGE04jk2rfvU79eFogop/eYTef7lwEfJetxJUs7cRhsETSI7+WX3IUnX8ruS9TiaIMLKl35VJZ5TRnFpz1qL2OCw8qEbnxa5eIPdZZbUI2gIRK96BtmP6Gp+tB/aplbq4u8THXA==" Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:08 volumio volumio[11074]: info: [1774736588731] CoreMusicLibrary::Adding element YouTube Music Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio volumio[11074]: Cannot find translation for source YouTube Music Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:08 volumio volumio[11074]: info: [1774736588735] CoreMusicLibrary::Adding element Podcast Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio volumio[11074]: Cannot find translation for source YouTube Music Mar 28 22:23:08 volumio volumio[11074]: Cannot find translation for source Podcast Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Starting plugin Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 28 22:23:08 volumio volumio[11074]: info: Volumio Calling Home Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Database loaded at: 2026-03-28T22:23:08.778Z Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:08 volumio volumio[11074]: info: [1774736588810] CoreMusicLibrary::Adding element FM/DAB Radio Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:08 volumio volumio[11074]: Cannot find translation for source YouTube Music Mar 28 22:23:08 volumio volumio[11074]: Cannot find translation for source Podcast Mar 28 22:23:08 volumio volumio[11074]: Cannot find translation for source FM/DAB Radio Mar 28 22:23:08 volumio volumio[11074]: info: [RTL-SDR Radio] Plugin started successfully Mar 28 22:23:08 volumio volumio[11074]: info: MPD Permissions set Mar 28 22:23:08 volumio volumio[11074]: info: MPD Permissions set Mar 28 22:23:08 volumio volumio[11074]: info: Spotify config file written Mar 28 22:23:08 volumio sudo[11281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:23:08 volumio sudo[11281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio volumio[11074]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio systemd[1]: go-librespot-daemon.service: Killing process 11159 (go-librespot) with signal SIGKILL. Mar 28 22:23:08 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:23:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:08 volumio volumio[11074]: info: No need to fix Spotify hosts Mar 28 22:23:08 volumio volumio[11074]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:23:08 volumio volumio[11074]: info: Discovery: Found device Volumio Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio volumio[11074]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:23:08 volumio volumio[11074]: info: Discovery: Found device Volumio Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:08 volumio go-librespot[11293]: go-librespot daemon starting... Mar 28 22:23:08 volumio sudo[11281]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:08 volumio volumio[11074]: info: Starting Shairport Sync Mar 28 22:23:08 volumio go-librespot[11294]: time="2026-03-28T22:23:08Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:08 volumio go-librespot[11294]: time="2026-03-28T22:23:08Z" level=debug msg="app state loaded" Mar 28 22:23:08 volumio go-librespot[11294]: time="2026-03-28T22:23:08Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:08 volumio volumio[11074]: info: Starting Shairport Sync Mar 28 22:23:08 volumio volumio[11074]: info: Starting Shairport Sync Mar 28 22:23:08 volumio sudo[11301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:08 volumio sudo[11301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio sudo[11303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:08 volumio sudo[11303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio sudo[11305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:08 volumio sudo[11305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:08 volumio volumio[11074]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:08 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:23:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:23:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:23:08 volumio systemd[1]: shairport-sync.service: Consumed 1.552s CPU time. Mar 28 22:23:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:23:09 volumio sudo[11303]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:09 volumio sudo[11301]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:09 volumio volumio[11074]: info: Shairport-Sync Started Mar 28 22:23:09 volumio volumio[11074]: Error adding Membership: Error: addMembership EINVAL Mar 28 22:23:09 volumio volumio[11074]: info: Shairport-Sync Started Mar 28 22:23:09 volumio sudo[11305]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:09 volumio volumio[11074]: info: Shairport-Sync Started Mar 28 22:23:09 volumio volumio[11074]: info: Volumio called home Mar 28 22:23:09 volumio mpd[11259]: 2026-03-28T22:23:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 22:23:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 28 22:23:09 volumio sudo[11223]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:09 volumio sudo[11215]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:09 volumio volumio[11074]: info: Completed starting Core Plugins Mar 28 22:23:09 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:09 volumio volumio[11074]: info: ----- MyVolumio plugins startup ---- Mar 28 22:23:09 volumio volumio[11074]: info: ------------------------------------------- Mar 28 22:23:09 volumio volumio[11074]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 28 22:23:09 volumio volumio[11074]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:23:09 volumio volumio[11074]: assert.ok(self.idling) Mar 28 22:23:09 volumio volumio[11074]: error: The expression evaluated to a falsy value: Mar 28 22:23:09 volumio volumio[11074]: assert.ok(self.idling) Mar 28 22:23:09 volumio volumio[11074]: info: MPD running with PID11259 Mar 28 22:23:09 volumio volumio[11074]: ,establishing connection Mar 28 22:23:09 volumio volumio[11074]: error: updateQueue error: null Mar 28 22:23:09 volumio go-librespot[11294]: time="2026-03-28T22:23:09Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:09 volumio go-librespot[11294]: time="2026-03-28T22:23:09Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:09 volumio go-librespot[11294]: time="2026-03-28T22:23:09Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:09 volumio volumio[11074]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 28 22:23:09 volumio volumio[11074]: error: updateQueue error: null Mar 28 22:23:09 volumio go-librespot[11294]: time="2026-03-28T22:23:09Z" level=info msg="zeroconf server listening on port 40917" Mar 28 22:23:09 volumio go-librespot[11294]: time="2026-03-28T22:23:09Z" level=debug msg="obtained new client token: AACwTn2Wf3S3pJrPupROObKi466rivOUezPfQBkcDPiVFrhcESR3FNJobu7Ac0e5zxtmf5Xm9Wj4iU55BNnWmOqSCmc8o4z0HSpiWLJ1mVakRX/16JQO8jXa83BEIretY4mm9zA7DvZqsvbwGUH51vx12IafaTqPlzFbvrsAkBiFwjCQ4rqcCARTrAlXa3LHjnw/iroOcN/ttGwURhLxAji7/T9uKHOt559MktB5zYn0lxsIA/2uufkBrg==" Mar 28 22:23:09 volumio go-librespot[11294]: time="2026-03-28T22:23:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=debug msg="completed keyexchange" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=debug msg="completed challenge" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:10 volumio volumio-remote-updater[945]: [2026-03-28 22:23:10] [connect] Successful connection Mar 28 22:23:10 volumio volumio-remote-updater[945]: [2026-03-28 22:23:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774736590 101 Mar 28 22:23:10 volumio volumio[11074]: 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: 2 Mar 28 22:23:10 volumio sudo[11113]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=debug msg="completed keyexchange" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=debug msg="completed challenge" Mar 28 22:23:10 volumio go-librespot[11294]: time="2026-03-28T22:23:10Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:11 volumio go-librespot[11294]: time="2026-03-28T22:23:11Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:23:11 volumio go-librespot[11294]: time="2026-03-28T22:23:11Z" level=debug msg="completed keyexchange" Mar 28 22:23:11 volumio go-librespot[11294]: time="2026-03-28T22:23:11Z" level=debug msg="completed challenge" Mar 28 22:23:11 volumio go-librespot[11294]: time="2026-03-28T22:23:11Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:11 volumio volumio[11074]: info: go-librespot daemon successfully initialized Mar 28 22:23:12 volumio go-librespot[11294]: time="2026-03-28T22:23:12Z" level=debug msg="connected to ap-gue1.spotify.com:443" Mar 28 22:23:12 volumio go-librespot[11294]: time="2026-03-28T22:23:12Z" level=debug msg="completed keyexchange" Mar 28 22:23:12 volumio go-librespot[11294]: time="2026-03-28T22:23:12Z" level=debug msg="completed challenge" Mar 28 22:23:12 volumio go-librespot[11294]: time="2026-03-28T22:23:12Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:13 volumio go-librespot[11294]: time="2026-03-28T22:23:13Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 28 22:23:13 volumio go-librespot[11294]: time="2026-03-28T22:23:13Z" level=debug msg="completed keyexchange" Mar 28 22:23:13 volumio go-librespot[11294]: time="2026-03-28T22:23:13Z" level=debug msg="completed challenge" Mar 28 22:23:13 volumio go-librespot[11294]: time="2026-03-28T22:23:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:14 volumio go-librespot[11294]: time="2026-03-28T22:23:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:14 volumio go-librespot[11294]: time="2026-03-28T22:23:14Z" level=debug msg="completed keyexchange" Mar 28 22:23:14 volumio go-librespot[11294]: time="2026-03-28T22:23:14Z" level=debug msg="completed challenge" Mar 28 22:23:14 volumio go-librespot[11294]: time="2026-03-28T22:23:14Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:14 volumio go-librespot[11294]: time="2026-03-28T22:23:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:14 volumio volumio[11074]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:14 volumio volumio[11074]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:23:16 volumio sudo[11348]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:16 volumio sudo[11348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:16 volumio sudo[11350]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:16 volumio sudo[11348]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:16 volumio sudo[11350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:16 volumio sudo[11350]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:16 volumio sudo[11353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 28 22:23:16 volumio sudo[11353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:16 volumio sudo[11353]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:16 volumio volumio[11074]: info: Upmpdcli Daemon Started Mar 28 22:23:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 28 22:23:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:17 volumio go-librespot[11356]: go-librespot daemon starting... Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="app state loaded" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=info msg="zeroconf server listening on port 36337" Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="obtained new client token: AABpxFNgXtov+bzwm0MExkTZyW8bDcWDUmER01rvf0RvQ+htW6ZO244GspkIDX24rnnktA9OCfxV3Iy/LmvPpPbjmMcWlywkuhtDGO/8sX5hvz1IrKJXZuNHFhW8DYUySw13O6dKAj66zDjHJ+gjah16FVSHVIfOvPSeyjCRiCDt6UDxirgjAcegdcBaaxSS+/SY1M7MAeuLtZgWVAIZ1wNvvWdwG60TapsRi2VB/HWruT6Gmbg2aYEGYQ==" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="completed keyexchange" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=debug msg="completed challenge" Mar 28 22:23:17 volumio go-librespot[11357]: time="2026-03-28T22:23:17Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 22:23:17 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:17 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:17 volumio volumio[11074]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 22:23:17 volumio volumio[11074]: info: MyVolumio login type: Token Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 22:23:17 volumio volumio[11074]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 22:23:18 volumio volumio[11074]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 22:23:18 volumio volumio[11074]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 22:23:18 volumio volumio[11074]: info: Streaming services startup Mar 28 22:23:18 volumio volumio[11074]: info: Starting Streaming Daemon Mar 28 22:23:18 volumio sudo[11366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:18 volumio sudo[11366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:18 volumio volumio[11074]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 22:23:18 volumio sudo[11366]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:18 volumio volumio[11074]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:18 volumio volumio[11074]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:18 volumio volumio[11074]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:18 volumio volumio[11074]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:18 volumio go-librespot[11357]: time="2026-03-28T22:23:18Z" level=debug msg="new websocket client" Mar 28 22:23:18 volumio volumio[11074]: info: Connection to go-librespot Websocket established Mar 28 22:23:18 volumio go-librespot[11357]: time="2026-03-28T22:23:18Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:18 volumio go-librespot[11357]: time="2026-03-28T22:23:18Z" level=debug msg="completed keyexchange" Mar 28 22:23:18 volumio go-librespot[11357]: time="2026-03-28T22:23:18Z" level=debug msg="completed challenge" Mar 28 22:23:18 volumio go-librespot[11357]: time="2026-03-28T22:23:18Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:18 volumio volumio[11074]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=debug msg="completed keyexchange" Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=debug msg="completed challenge" Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:19 volumio volumio[11074]: info: MyVolumio token set successfully Mar 28 22:23:19 volumio volumio[11074]: info: MYVOLUMIO: Adding device Mar 28 22:23:19 volumio volumio[11074]: info: MYVOLUMIO: Evaluating Server Mar 28 22:23:19 volumio volumio[11074]: info: MyVolumio status changed Mar 28 22:23:19 volumio volumio[11074]: info: Streaming services startup Mar 28 22:23:19 volumio volumio[11074]: info: Starting Streaming Daemon Mar 28 22:23:19 volumio volumio[11074]: info: Removing browser output: myVolumio user plan is not superstar Mar 28 22:23:19 volumio volumio[11074]: info: Removing audio output: Mar 28 22:23:19 volumio volumio[11074]: info: Stoppping Tunnel 1 Mar 28 22:23:19 volumio sudo[11393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:19 volumio sudo[11393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:19 volumio sudo[11395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 28 22:23:19 volumio sudo[11395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:19 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. Mar 28 22:23:19 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. Mar 28 22:23:19 volumio sudo[11393]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:19 volumio volumio[11074]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:19 volumio volumio[11074]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:19 volumio volumio[11074]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:19 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. Mar 28 22:23:19 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. Mar 28 22:23:19 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. Mar 28 22:23:19 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. Mar 28 22:23:19 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. Mar 28 22:23:19 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. Mar 28 22:23:19 volumio sudo[11395]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:19 volumio volumio[11074]: info: Remote SSH Stopped Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=debug msg="completed keyexchange" Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=debug msg="completed challenge" Mar 28 22:23:19 volumio go-librespot[11357]: time="2026-03-28T22:23:19Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:19 volumio volumio[11074]: info: Setting Geolocation for MyVolumio to eu3 Mar 28 22:23:19 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:19 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:19 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:20 volumio go-librespot[11357]: time="2026-03-28T22:23:20Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 28 22:23:20 volumio volumio[11074]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 28 22:23:20 volumio go-librespot[11357]: time="2026-03-28T22:23:20Z" level=debug msg="completed keyexchange" Mar 28 22:23:20 volumio go-librespot[11357]: time="2026-03-28T22:23:20Z" level=debug msg="completed challenge" Mar 28 22:23:20 volumio volumio[11074]: info: Updating MyVolumio device info Mar 28 22:23:20 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:20 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:20 volumio volumio[11074]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:21 volumio go-librespot[11357]: time="2026-03-28T22:23:21Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:21 volumio volumio[11074]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 28 22:23:21 volumio volumio[11074]: info: Getting Spotify volume Mar 28 22:23:21 volumio volumio[11074]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 28 22:23:21 volumio volumio[11074]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:21 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:21 volumio volumio[11074]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 28 22:23:21 volumio volumio[11074]: SPOTIFY: SPOTIFY VOLUME undefined Mar 28 22:23:21 volumio volumio[11074]: SPOTIFY: VOLUMIO VOLUME 0 Mar 28 22:23:21 volumio volumio[11074]: info: Aligning Spotify Volume to Volumio Volume Mar 28 22:23:21 volumio volumio[11074]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:21 volumio volumio[11074]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:21 volumio volumio[11074]: info: Setting Spotify Volume from Volumio: 0 Mar 28 22:23:21 volumio go-librespot[11357]: time="2026-03-28T22:23:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:22 volumio go-librespot[11357]: time="2026-03-28T22:23:22Z" level=debug msg="completed keyexchange" Mar 28 22:23:22 volumio go-librespot[11357]: time="2026-03-28T22:23:22Z" level=debug msg="completed challenge" Mar 28 22:23:22 volumio go-librespot[11357]: time="2026-03-28T22:23:22Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:22 volumio go-librespot[11357]: time="2026-03-28T22:23:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:22 volumio volumio[11074]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:22 volumio volumio[11074]: Error: socket hang up Mar 28 22:23:22 volumio volumio[11074]: at connResetException (node:internal/errors:720:14) Mar 28 22:23:22 volumio volumio[11074]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 28 22:23:22 volumio volumio[11074]: at Socket.emit (node:events:526:35) Mar 28 22:23:22 volumio volumio[11074]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 28 22:23:22 volumio volumio[11074]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 28 22:23:22 volumio volumio[11074]: code: 'ECONNRESET', Mar 28 22:23:22 volumio volumio[11074]: response: undefined Mar 28 22:23:22 volumio volumio[11074]: } Mar 28 22:23:22 volumio volumio[11074]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:22 volumio sudo[11412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:22' Mar 28 22:23:22 volumio sudo[11412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:22 volumio sudo[11412]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:22 volumio volumio-remote-updater[945]: [2026-03-28 22:23:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 28 22:23:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:22 volumio volumio-remote-updater[945]: [2026-03-28 22:23:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 28 22:23:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 28 22:23:22 volumio systemd[1]: volumio.service: Consumed 9.048s CPU time. Mar 28 22:23:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 87502. Mar 28 22:23:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 28 22:23:22 volumio systemd[1]: volumio.service: Consumed 9.048s CPU time. Mar 28 22:23:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 28 22:23:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:23 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:23 volumio volumio[11424]: info: ----- Volumio3 ---- Mar 28 22:23:23 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:23 volumio volumio[11424]: info: ----- System startup ---- Mar 28 22:23:23 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:23 volumio volumio[11424]: info: MYVOLUMIO Environment detected Mar 28 22:23:23 volumio volumio[11424]: info: Plugin folders cleanup Mar 28 22:23:23 volumio volumio[11424]: info: Scanning into folder /volumio/app/plugins/ Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category audio_interface Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category miscellanea Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category music_service Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category plugins.json Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category system_controller Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category user_interface Mar 28 22:23:23 volumio volumio[11424]: info: Scanning into folder /data/plugins/ Mar 28 22:23:23 volumio volumio[11424]: info: Scanning category music_service Mar 28 22:23:23 volumio volumio[11424]: info: Plugin folders cleanup completed Mar 28 22:23:23 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:23 volumio volumio[11424]: info: ----- Core plugins startup ---- Mar 28 22:23:23 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:23 volumio volumio[11424]: info: Loading plugins from folder /volumio/app/plugins/ Mar 28 22:23:23 volumio volumio[11424]: info: Adding plugin upnp to MyMusic Plugins Mar 28 22:23:23 volumio volumio[11424]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 28 22:23:23 volumio volumio[11424]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 28 22:23:23 volumio volumio[11424]: info: Loading plugins from folder /data/plugins/ Mar 28 22:23:23 volumio volumio[11424]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 28 22:23:23 volumio volumio[11424]: info: Loading plugin "system"... Mar 28 22:23:23 volumio volumio[11424]: info: Loading plugin "appearance"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "network"... Mar 28 22:23:24 volumio volumio[11424]: info: Refreshing Cached IP Addresses Mar 28 22:23:24 volumio sudo[11452]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:24 volumio sudo[11452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:24 volumio sudo[11452]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:24 volumio sudo[11454]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:24 volumio sudo[11454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:24 volumio sudo[11454]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "services"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "alsa_controller"... Mar 28 22:23:24 volumio sudo[11462]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 28 22:23:24 volumio sudo[11462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:24 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "wizard"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "networkfs"... Mar 28 22:23:24 volumio volumio[11424]: info: Starting Udev Watcher for removable devices Mar 28 22:23:24 volumio volumio[11424]: info: Mounting Device 0ACB-A1DE Mar 28 22:23:24 volumio sudo[11491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:24 volumio sudo[11491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:24 volumio sudo[11491]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:24 volumio volumio[11424]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:24 volumio volumio[11424]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:24 volumio volumio[11424]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:24 volumio volumio[11424]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:24 volumio volumio[11424]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:24 volumio volumio[11424]: info: Ignoring mount for partition: boot Mar 28 22:23:24 volumio volumio[11424]: info: Ignoring mount for partition: volumio Mar 28 22:23:24 volumio volumio[11424]: info: Ignoring mount for partition: volumio_data Mar 28 22:23:24 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "volumio_command_line_client"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "upnp"... Mar 28 22:23:24 volumio volumio[11424]: info: [1774736604111] Starting Upmpd Daemon Mar 28 22:23:24 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "my_music"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "mpd"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "upnp_browser"... Mar 28 22:23:24 volumio volumio[11424]: info: Starting UPNP Browser Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "alarm-clock"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "airplay_emulation"... Mar 28 22:23:24 volumio volumio[11424]: info: Starting Shairport Sync Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "last_100"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "webradio"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "i2s_dacs"... Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "volumiodiscovery"... Mar 28 22:23:24 volumio volumio[11424]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:24 volumio volumio[11424]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:24 volumio volumio[11424]: *** WARNING *** For more information see Mar 28 22:23:24 volumio volumio[11424]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:24 volumio volumio[11424]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:24 volumio volumio[11424]: *** WARNING *** For more information see Mar 28 22:23:24 volumio node[11424]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:24 volumio node[11424]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:24 volumio node[11424]: *** WARNING *** For more information see Mar 28 22:23:24 volumio node[11424]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:24 volumio node[11424]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:24 volumio node[11424]: *** WARNING *** For more information see Mar 28 22:23:24 volumio volumio[11424]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 28 22:23:24 volumio volumio[11424]: info: Discovery: Started advertising with name: Volumio Mar 28 22:23:24 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:24 volumio volumio[11424]: info: Loading plugin "spop"... Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "ytmusic"... Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "outputs"... Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "albumart"... Mar 28 22:23:25 volumio volumio[11424]: info: Plugin example_plugin is not enabled Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "inputs"... Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "updater_comm"... Mar 28 22:23:25 volumio volumio[11424]: info: Plugin mpdemulation is not enabled Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "rest_api"... Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "websocket"... Mar 28 22:23:25 volumio volumio[11424]: info: Starting Socket.io Server version 1.7.4 Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "podcast"... Mar 28 22:23:25 volumio volumio[11424]: info: ControllerPodcast::constructor Mar 28 22:23:25 volumio volumio[11424]: info: Loading plugin "rtlsdr_radio"... Mar 28 22:23:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 28 22:23:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:25 volumio go-librespot[11505]: go-librespot daemon starting... Mar 28 22:23:25 volumio volumio[11495]: Forking 3 albumart workers Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=debug msg="app state loaded" Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:25 volumio volumio[11424]: info: Loading i18n strings for locale en Mar 28 22:23:25 volumio volumio[11424]: Updating browse sources language Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::initPlayerControls Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: Express server listening on port 3000 Mar 28 22:23:25 volumio volumio[11424]: [Metrics] WebUI: 2s 319.66ms Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::resetVolumioState Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::getcurrentVolume Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:25 volumio volumio[11424]: info: Volumio Network Manager: Network status updated: 2 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: Reloading queue from file Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::setRepeat null single undefined Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::pushState Mar 28 22:23:25 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::setRandom true Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::pushState Mar 28 22:23:25 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:25 volumio volumio[11424]: info: Setting Device type: Raspberry PI Mar 28 22:23:25 volumio volumio[11424]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 28 22:23:25 volumio volumio[11424]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 28 22:23:25 volumio volumio[11424]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 28 22:23:25 volumio volumio[11424]: info: Completed loading Core Plugins Mar 28 22:23:25 volumio volumio[11424]: info: Preparing to generate the ALSA configuration file Mar 28 22:23:25 volumio volumio[11424]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::pushState Mar 28 22:23:25 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:25 volumio volumio[11424]: info: CoreStateMachine::updateTrackBlock Mar 28 22:23:25 volumio volumio[11424]: info: CorePlayQueue::getTrackBlock Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:25 volumio volumio[11424]: info: Asound.conf file unchanged, so no further update is needed Mar 28 22:23:25 volumio volumio[11424]: info: Output device has changed, restarting MPD Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:25 volumio go-librespot[11506]: time="2026-03-28T22:23:25Z" level=info msg="zeroconf server listening on port 37823" Mar 28 22:23:25 volumio volumio[11424]: info: Output device has changed, restarting Shairport Sync Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:25 volumio sudo[11560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:25 volumio sudo[11560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:25 volumio sudo[11560]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:25 volumio sudo[11563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:25 volumio sudo[11563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:25 volumio volumio[11424]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:25 volumio volumio[11513]: Starting albumart workers Mar 28 22:23:25 volumio volumio[11424]: info: ___________ START PLUGINS ___________ Mar 28 22:23:25 volumio volumio[11424]: info: ControllerMpd::onStart: Initializing MPD Mar 28 22:23:25 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 28 22:23:25 volumio volumio[11424]: info: Creating MPD Configuration file Mar 28 22:23:25 volumio volumio[11514]: Starting albumart workers Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:25 volumio volumio[11424]: info: [1774736605896] CoreMusicLibrary::Adding element Media Servers Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:25 volumio volumio[11424]: info: UPNP Browser: Client initialized successfully Mar 28 22:23:25 volumio sudo[11571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:25 volumio volumio[11512]: Starting albumart workers Mar 28 22:23:25 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:25 volumio sudo[11571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:25 volumio sudo[11573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:25 volumio sudo[11571]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:25 volumio sudo[11573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:25 volumio volumio[11424]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:25 volumio volumio[11424]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:25 volumio volumio[11424]: info: [1774736605944] CoreMusicLibrary::Adding element Last_100 Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:25 volumio volumio[11424]: info: [1774736605947] CoreMusicLibrary::Adding element Webradio Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:25 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:25 volumio volumio[11424]: info: Initializing BBC Radios Mar 28 22:23:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:25 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: Creating Spotify config file Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio sudo[11595]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:23:26 volumio sudo[11595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:23:26 volumio sudo[11595]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:26 volumio volumio[11424]: info: [1774736606146] CoreMusicLibrary::Adding element YouTube Music Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:26 volumio volumio[11424]: Cannot find translation for source YouTube Music Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:26 volumio volumio[11424]: info: [1774736606151] CoreMusicLibrary::Adding element Podcast Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:26 volumio volumio[11424]: Cannot find translation for source YouTube Music Mar 28 22:23:26 volumio volumio[11424]: Cannot find translation for source Podcast Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Starting plugin Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 28 22:23:26 volumio volumio[11424]: info: Volumio Calling Home Mar 28 22:23:26 volumio go-librespot[11506]: time="2026-03-28T22:23:26Z" level=debug msg="obtained new client token: AAAcQQVesXl7mUnpfrWXLtpSf9lqszvEo8YLAQsNd+1wOR5LOAoirG5Zu3ATSb5OT/t8TVY1Z7w/Biaym0+E1+oT7Xm8RFGTwh7w4rwvXM8qwpldbIbsO0O09qYaAT11YNMMCa9l1e/6B6kRvHTy/nnfyCjz25Aaq90Tjr4RHoTxpNXqeiBe/jJ+dP8UtTjujRT7t16Tm5lLZY9LRp1IiEu4l+mXJ2eKICmOUEwAo8oK1o/GVJnqaAA=" Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Database loaded at: 2026-03-28T22:23:26.224Z Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:26 volumio volumio[11424]: info: [1774736606262] CoreMusicLibrary::Adding element FM/DAB Radio Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:26 volumio volumio[11424]: Cannot find translation for source YouTube Music Mar 28 22:23:26 volumio volumio[11424]: Cannot find translation for source Podcast Mar 28 22:23:26 volumio volumio[11424]: Cannot find translation for source FM/DAB Radio Mar 28 22:23:26 volumio volumio[11424]: info: [RTL-SDR Radio] Plugin started successfully Mar 28 22:23:26 volumio volumio[11424]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:26 volumio volumio[11424]: info: CoreStateMachine::pushState Mar 28 22:23:26 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:26 volumio volumio[11424]: info: MPD Permissions set Mar 28 22:23:26 volumio volumio[11424]: info: MPD Permissions set Mar 28 22:23:26 volumio volumio[11424]: info: Spotify config file written Mar 28 22:23:26 volumio sudo[11630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:23:26 volumio sudo[11630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:26 volumio volumio[11424]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:23:26 volumio systemd[1]: go-librespot-daemon.service: Killing process 11544 (go-librespot) with signal SIGKILL. Mar 28 22:23:26 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:23:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:26 volumio volumio[11424]: info: No need to fix Spotify hosts Mar 28 22:23:26 volumio volumio[11424]: info: Starting Shairport Sync Mar 28 22:23:26 volumio volumio[11424]: info: Starting Shairport Sync Mar 28 22:23:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:26 volumio go-librespot[11637]: go-librespot daemon starting... Mar 28 22:23:26 volumio sudo[11630]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio volumio[11424]: info: Starting Shairport Sync Mar 28 22:23:26 volumio sudo[11644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=debug msg="app state loaded" Mar 28 22:23:26 volumio sudo[11644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:26 volumio sudo[11652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:26 volumio sudo[11652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:26 volumio volumio[11424]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:23:26 volumio volumio[11424]: info: Discovery: Found device Volumio Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:26 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:26 volumio sudo[11656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:26 volumio sudo[11656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:26 volumio volumio[11424]: info: Volumio called home Mar 28 22:23:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:23:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:23:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:23:26 volumio systemd[1]: shairport-sync.service: Consumed 1.560s CPU time. Mar 28 22:23:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:26 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:26 volumio sudo[11652]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio sudo[11644]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio sudo[11656]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio volumio[11424]: info: Shairport-Sync Started Mar 28 22:23:26 volumio volumio[11424]: Error adding Membership: Error: addMembership EINVAL Mar 28 22:23:26 volumio volumio[11424]: info: Shairport-Sync Started Mar 28 22:23:26 volumio volumio[11424]: info: Shairport-Sync Started Mar 28 22:23:26 volumio volumio[11424]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:23:26 volumio volumio[11424]: info: Discovery: Found device Volumio Mar 28 22:23:26 volumio volumio[11424]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:26 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:26 volumio volumio[11424]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 28 22:23:26 volumio mpd[11602]: 2026-03-28T22:23:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 22:23:26 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 28 22:23:26 volumio sudo[11573]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio sudo[11563]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:26 volumio volumio[11424]: info: Completed starting Core Plugins Mar 28 22:23:26 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:26 volumio volumio[11424]: info: ----- MyVolumio plugins startup ---- Mar 28 22:23:26 volumio volumio[11424]: info: ------------------------------------------- Mar 28 22:23:26 volumio volumio[11424]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 28 22:23:26 volumio volumio[11424]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:23:26 volumio volumio[11424]: assert.ok(self.idling) Mar 28 22:23:26 volumio volumio[11424]: error: The expression evaluated to a falsy value: Mar 28 22:23:26 volumio volumio[11424]: assert.ok(self.idling) Mar 28 22:23:26 volumio volumio[11424]: info: MPD running with PID11602 Mar 28 22:23:26 volumio volumio[11424]: ,establishing connection Mar 28 22:23:26 volumio volumio[11424]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:23:26 volumio volumio[11424]: assert.ok(self.idling) Mar 28 22:23:26 volumio volumio[11424]: error: The expression evaluated to a falsy value: Mar 28 22:23:26 volumio volumio[11424]: assert.ok(self.idling) Mar 28 22:23:26 volumio volumio[11424]: error: updateQueue error: null Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:26 volumio go-librespot[11645]: time="2026-03-28T22:23:26Z" level=info msg="zeroconf server listening on port 43003" Mar 28 22:23:27 volumio go-librespot[11645]: time="2026-03-28T22:23:27Z" level=debug msg="obtained new client token: AAB6xmesKb3TQwBA+07G4D+OppiNgr479KDn5zhw/TFYXEZFpV5jJVsl/+LC3GeAYk43aRqErvEqeYVdtxggA1JMpFfqnqyPfRtekDNfrAQUKUOdFMkzHFZiEACigyXCyUZHB70BXctPG+KYroX5m38YC1nqQWiDAuxt2TLuqfKhx+2+h/X+E8vVRw8i1PQ1D/4T0o5fkfCeF5XGAGyZzn/lf1To5Xq9RSTI+1fEwLHvzXeECmLkjgMG8g==" Mar 28 22:23:27 volumio go-librespot[11645]: time="2026-03-28T22:23:27Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:27 volumio go-librespot[11645]: time="2026-03-28T22:23:27Z" level=debug msg="completed keyexchange" Mar 28 22:23:27 volumio go-librespot[11645]: time="2026-03-28T22:23:27Z" level=debug msg="completed challenge" Mar 28 22:23:27 volumio volumio-remote-updater[945]: [2026-03-28 22:23:27] [connect] Successful connection Mar 28 22:23:27 volumio volumio-remote-updater[945]: [2026-03-28 22:23:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774736607 101 Mar 28 22:23:27 volumio volumio[11424]: 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: 2 Mar 28 22:23:27 volumio go-librespot[11645]: time="2026-03-28T22:23:27Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:27 volumio sudo[11462]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=debug msg="completed keyexchange" Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=debug msg="completed challenge" Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=debug msg="completed keyexchange" Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=debug msg="completed challenge" Mar 28 22:23:28 volumio go-librespot[11645]: time="2026-03-28T22:23:28Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:29 volumio volumio[11424]: info: go-librespot daemon successfully initialized Mar 28 22:23:29 volumio go-librespot[11645]: time="2026-03-28T22:23:29Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:23:29 volumio go-librespot[11645]: time="2026-03-28T22:23:29Z" level=debug msg="completed keyexchange" Mar 28 22:23:29 volumio go-librespot[11645]: time="2026-03-28T22:23:29Z" level=debug msg="completed challenge" Mar 28 22:23:29 volumio go-librespot[11645]: time="2026-03-28T22:23:29Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:30 volumio go-librespot[11645]: time="2026-03-28T22:23:30Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:23:30 volumio go-librespot[11645]: time="2026-03-28T22:23:30Z" level=debug msg="completed keyexchange" Mar 28 22:23:30 volumio go-librespot[11645]: time="2026-03-28T22:23:30Z" level=debug msg="completed challenge" Mar 28 22:23:30 volumio go-librespot[11645]: time="2026-03-28T22:23:30Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:31 volumio go-librespot[11645]: time="2026-03-28T22:23:31Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 28 22:23:31 volumio go-librespot[11645]: time="2026-03-28T22:23:31Z" level=debug msg="completed keyexchange" Mar 28 22:23:31 volumio go-librespot[11645]: time="2026-03-28T22:23:31Z" level=debug msg="completed challenge" Mar 28 22:23:31 volumio go-librespot[11645]: time="2026-03-28T22:23:31Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:31 volumio go-librespot[11645]: time="2026-03-28T22:23:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:32 volumio volumio[11424]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:32 volumio volumio[11424]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:23:34 volumio sudo[11696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:34 volumio sudo[11696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:34 volumio sudo[11698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:34 volumio sudo[11696]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:34 volumio sudo[11698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:34 volumio sudo[11698]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:34 volumio sudo[11702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 28 22:23:34 volumio sudo[11702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:34 volumio sudo[11702]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:34 volumio volumio[11424]: info: Upmpdcli Daemon Started Mar 28 22:23:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 28 22:23:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:34 volumio go-librespot[11704]: go-librespot daemon starting... Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="app state loaded" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=info msg="zeroconf server listening on port 45241" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="obtained new client token: AAC9OrT58gQOLoaVWPxaclz3ShnSFCjsjB0AfwOrS0HEGLhiApDZeaIhBp6nCPkb4eXslycIkBT5tI8PqQx8RWhLkbYE6yBYDZ2N5GqQDEU331aIZkyhsguHggb6dBubd7AOWSDj4I9jZ/A7Z9/Q8pUVB0Z1kIUZBFhYDKY7+b3N/D8Btkm4rs8CUZHfdd22fX3H4QIst4P94H9LdrZAiEAp00zTLr0cMpotSQvE294k0XYESXLJyuNEXg==" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="completed keyexchange" Mar 28 22:23:34 volumio go-librespot[11705]: time="2026-03-28T22:23:34Z" level=debug msg="completed challenge" Mar 28 22:23:35 volumio go-librespot[11705]: time="2026-03-28T22:23:35Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 22:23:35 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:35 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:35 volumio volumio[11424]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 22:23:35 volumio volumio[11424]: info: MyVolumio login type: Token Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 22:23:35 volumio go-librespot[11705]: time="2026-03-28T22:23:35Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:35 volumio go-librespot[11705]: time="2026-03-28T22:23:35Z" level=debug msg="completed keyexchange" Mar 28 22:23:35 volumio go-librespot[11705]: time="2026-03-28T22:23:35Z" level=debug msg="completed challenge" Mar 28 22:23:35 volumio go-librespot[11705]: time="2026-03-28T22:23:35Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 22:23:35 volumio volumio[11424]: info: Streaming services startup Mar 28 22:23:35 volumio volumio[11424]: info: Starting Streaming Daemon Mar 28 22:23:35 volumio sudo[11715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:35 volumio sudo[11715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:35 volumio volumio[11424]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 22:23:35 volumio sudo[11715]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:35 volumio volumio[11424]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:35 volumio volumio[11424]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:35 volumio volumio[11424]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:35 volumio volumio[11424]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:35 volumio go-librespot[11705]: time="2026-03-28T22:23:35Z" level=debug msg="new websocket client" Mar 28 22:23:35 volumio volumio[11424]: info: Connection to go-librespot Websocket established Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=debug msg="completed keyexchange" Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=debug msg="completed challenge" Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:36 volumio volumio[11424]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:23:36 volumio volumio[11424]: info: MyVolumio token set successfully Mar 28 22:23:36 volumio volumio[11424]: info: MYVOLUMIO: Adding device Mar 28 22:23:36 volumio volumio[11424]: info: MYVOLUMIO: Evaluating Server Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=debug msg="completed keyexchange" Mar 28 22:23:36 volumio go-librespot[11705]: time="2026-03-28T22:23:36Z" level=debug msg="completed challenge" Mar 28 22:23:37 volumio go-librespot[11705]: time="2026-03-28T22:23:37Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:37 volumio volumio[11424]: info: MyVolumio status changed Mar 28 22:23:37 volumio volumio[11424]: info: Streaming services startup Mar 28 22:23:37 volumio volumio[11424]: info: Starting Streaming Daemon Mar 28 22:23:37 volumio volumio[11424]: info: Removing browser output: myVolumio user plan is not superstar Mar 28 22:23:37 volumio volumio[11424]: info: Removing audio output: Mar 28 22:23:37 volumio volumio[11424]: info: Stoppping Tunnel 1 Mar 28 22:23:37 volumio sudo[11742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:37 volumio sudo[11742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:37 volumio sudo[11744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 28 22:23:37 volumio sudo[11744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:37 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. Mar 28 22:23:37 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. Mar 28 22:23:37 volumio sudo[11742]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:37 volumio volumio[11424]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:37 volumio volumio[11424]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:37 volumio volumio[11424]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:37 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. Mar 28 22:23:37 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. Mar 28 22:23:37 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. Mar 28 22:23:37 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. Mar 28 22:23:37 volumio sudo[11744]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:37 volumio volumio[11424]: info: Remote SSH Stopped Mar 28 22:23:37 volumio volumio[11424]: info: Setting Geolocation for MyVolumio to eu3 Mar 28 22:23:37 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:37 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:37 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:37 volumio go-librespot[11705]: time="2026-03-28T22:23:37Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:23:37 volumio volumio[11424]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 28 22:23:37 volumio go-librespot[11705]: time="2026-03-28T22:23:37Z" level=debug msg="completed keyexchange" Mar 28 22:23:37 volumio go-librespot[11705]: time="2026-03-28T22:23:37Z" level=debug msg="completed challenge" Mar 28 22:23:37 volumio go-librespot[11705]: time="2026-03-28T22:23:37Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:38 volumio volumio[11424]: info: Updating MyVolumio device info Mar 28 22:23:38 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:38 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:38 volumio volumio[11424]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:38 volumio go-librespot[11705]: time="2026-03-28T22:23:38Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 28 22:23:38 volumio go-librespot[11705]: time="2026-03-28T22:23:38Z" level=debug msg="completed keyexchange" Mar 28 22:23:38 volumio go-librespot[11705]: time="2026-03-28T22:23:38Z" level=debug msg="completed challenge" Mar 28 22:23:38 volumio volumio[11424]: info: Getting Spotify volume Mar 28 22:23:38 volumio volumio[11424]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 28 22:23:38 volumio volumio[11424]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:38 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:38 volumio volumio[11424]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 28 22:23:38 volumio volumio[11424]: SPOTIFY: SPOTIFY VOLUME undefined Mar 28 22:23:38 volumio volumio[11424]: SPOTIFY: VOLUMIO VOLUME 0 Mar 28 22:23:38 volumio volumio[11424]: info: Aligning Spotify Volume to Volumio Volume Mar 28 22:23:38 volumio volumio[11424]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:38 volumio volumio[11424]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:38 volumio volumio[11424]: info: Setting Spotify Volume from Volumio: 0 Mar 28 22:23:38 volumio go-librespot[11705]: time="2026-03-28T22:23:38Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:38 volumio go-librespot[11705]: time="2026-03-28T22:23:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:38 volumio volumio[11424]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:38 volumio volumio[11424]: Error: socket hang up Mar 28 22:23:38 volumio volumio[11424]: at connResetException (node:internal/errors:720:14) Mar 28 22:23:38 volumio volumio[11424]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 28 22:23:38 volumio volumio[11424]: at Socket.emit (node:events:526:35) Mar 28 22:23:38 volumio volumio[11424]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 28 22:23:38 volumio volumio[11424]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 28 22:23:38 volumio volumio[11424]: code: 'ECONNRESET', Mar 28 22:23:38 volumio volumio[11424]: response: undefined Mar 28 22:23:38 volumio volumio[11424]: } Mar 28 22:23:38 volumio volumio[11424]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:39 volumio sudo[11761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:22' Mar 28 22:23:39 volumio sudo[11761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:39 volumio sudo[11761]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:39 volumio volumio-remote-updater[945]: [2026-03-28 22:23:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 28 22:23:39 volumio volumio-remote-updater[945]: [2026-03-28 22:23:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 28 22:23:39 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:39 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 28 22:23:39 volumio systemd[1]: volumio.service: Consumed 8.887s CPU time. Mar 28 22:23:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:39 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 87503. Mar 28 22:23:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:39 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 28 22:23:39 volumio systemd[1]: volumio.service: Consumed 8.887s CPU time. Mar 28 22:23:39 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 28 22:23:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:39 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:40 volumio volumio[11774]: info: ----- Volumio3 ---- Mar 28 22:23:40 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:40 volumio volumio[11774]: info: ----- System startup ---- Mar 28 22:23:40 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:40 volumio volumio[11774]: info: MYVOLUMIO Environment detected Mar 28 22:23:40 volumio volumio[11774]: info: Plugin folders cleanup Mar 28 22:23:40 volumio volumio[11774]: info: Scanning into folder /volumio/app/plugins/ Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category audio_interface Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category miscellanea Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category music_service Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category plugins.json Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category system_controller Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category user_interface Mar 28 22:23:40 volumio volumio[11774]: info: Scanning into folder /data/plugins/ Mar 28 22:23:40 volumio volumio[11774]: info: Scanning category music_service Mar 28 22:23:40 volumio volumio[11774]: info: Plugin folders cleanup completed Mar 28 22:23:40 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:40 volumio volumio[11774]: info: ----- Core plugins startup ---- Mar 28 22:23:40 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugins from folder /volumio/app/plugins/ Mar 28 22:23:40 volumio volumio[11774]: info: Adding plugin upnp to MyMusic Plugins Mar 28 22:23:40 volumio volumio[11774]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 28 22:23:40 volumio volumio[11774]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugins from folder /data/plugins/ Mar 28 22:23:40 volumio volumio[11774]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "system"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "appearance"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "network"... Mar 28 22:23:40 volumio volumio[11774]: info: Refreshing Cached IP Addresses Mar 28 22:23:40 volumio sudo[11802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:40 volumio sudo[11802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:40 volumio sudo[11804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:40 volumio sudo[11804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:40 volumio sudo[11802]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:40 volumio sudo[11804]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "services"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "alsa_controller"... Mar 28 22:23:40 volumio sudo[11813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 28 22:23:40 volumio sudo[11813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:40 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "wizard"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "networkfs"... Mar 28 22:23:40 volumio volumio[11774]: info: Starting Udev Watcher for removable devices Mar 28 22:23:40 volumio volumio[11774]: info: Mounting Device 0ACB-A1DE Mar 28 22:23:40 volumio sudo[11841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:40 volumio sudo[11841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:40 volumio sudo[11841]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:40 volumio volumio[11774]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:40 volumio volumio[11774]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:40 volumio volumio[11774]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:40 volumio volumio[11774]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:40 volumio volumio[11774]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:40 volumio volumio[11774]: info: Ignoring mount for partition: boot Mar 28 22:23:40 volumio volumio[11774]: info: Ignoring mount for partition: volumio Mar 28 22:23:40 volumio volumio[11774]: info: Ignoring mount for partition: volumio_data Mar 28 22:23:40 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "volumio_command_line_client"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "upnp"... Mar 28 22:23:40 volumio volumio[11774]: info: [1774736620639] Starting Upmpd Daemon Mar 28 22:23:40 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "my_music"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "mpd"... Mar 28 22:23:40 volumio volumio[11774]: info: Loading plugin "upnp_browser"... Mar 28 22:23:41 volumio volumio[11774]: info: Starting UPNP Browser Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "alarm-clock"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "airplay_emulation"... Mar 28 22:23:41 volumio volumio[11774]: info: Starting Shairport Sync Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "last_100"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "webradio"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "i2s_dacs"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "volumiodiscovery"... Mar 28 22:23:41 volumio volumio[11774]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:41 volumio volumio[11774]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:41 volumio volumio[11774]: *** WARNING *** For more information see Mar 28 22:23:41 volumio volumio[11774]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:41 volumio volumio[11774]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:41 volumio volumio[11774]: *** WARNING *** For more information see Mar 28 22:23:41 volumio node[11774]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:41 volumio node[11774]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:41 volumio node[11774]: *** WARNING *** For more information see Mar 28 22:23:41 volumio node[11774]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:41 volumio node[11774]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:41 volumio node[11774]: *** WARNING *** For more information see Mar 28 22:23:41 volumio volumio[11774]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 28 22:23:41 volumio volumio[11774]: info: Discovery: Started advertising with name: Volumio Mar 28 22:23:41 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "spop"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "ytmusic"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "outputs"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "albumart"... Mar 28 22:23:41 volumio volumio[11774]: info: Plugin example_plugin is not enabled Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "inputs"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "updater_comm"... Mar 28 22:23:41 volumio volumio[11774]: info: Plugin mpdemulation is not enabled Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "rest_api"... Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "websocket"... Mar 28 22:23:41 volumio volumio[11774]: info: Starting Socket.io Server version 1.7.4 Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "podcast"... Mar 28 22:23:41 volumio volumio[11774]: info: ControllerPodcast::constructor Mar 28 22:23:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 28 22:23:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:41 volumio volumio[11774]: info: Loading plugin "rtlsdr_radio"... Mar 28 22:23:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:41 volumio go-librespot[11855]: go-librespot daemon starting... Mar 28 22:23:41 volumio go-librespot[11856]: time="2026-03-28T22:23:41Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:41 volumio go-librespot[11856]: time="2026-03-28T22:23:41Z" level=debug msg="app state loaded" Mar 28 22:23:41 volumio go-librespot[11856]: time="2026-03-28T22:23:41Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:41 volumio volumio[11845]: Forking 3 albumart workers Mar 28 22:23:42 volumio volumio[11774]: info: Loading i18n strings for locale en Mar 28 22:23:42 volumio volumio[11774]: Updating browse sources language Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::initPlayerControls Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: Express server listening on port 3000 Mar 28 22:23:42 volumio volumio[11774]: [Metrics] WebUI: 2s 298.67ms Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::resetVolumioState Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::getcurrentVolume Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:42 volumio volumio[11774]: info: Volumio Network Manager: Network status updated: 2 Mar 28 22:23:42 volumio volumio[11774]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::pushState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::updateTrackBlock Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrackBlock Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: Reloading queue from file Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::setRepeat null single undefined Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::pushState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::setRandom true Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::pushState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:42 volumio volumio[11774]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 28 22:23:42 volumio volumio[11774]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 28 22:23:42 volumio volumio[11774]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 28 22:23:42 volumio volumio[11774]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:42 volumio volumio[11774]: info: CoreStateMachine::pushState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:42 volumio volumio[11774]: info: Setting Device type: Raspberry PI Mar 28 22:23:42 volumio volumio[11774]: info: Completed loading Core Plugins Mar 28 22:23:42 volumio volumio[11774]: info: Preparing to generate the ALSA configuration file Mar 28 22:23:42 volumio go-librespot[11856]: time="2026-03-28T22:23:42Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:42 volumio go-librespot[11856]: time="2026-03-28T22:23:42Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:42 volumio go-librespot[11856]: time="2026-03-28T22:23:42Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:42 volumio volumio[11774]: info: Asound.conf file unchanged, so no further update is needed Mar 28 22:23:42 volumio volumio[11774]: info: Output device has changed, restarting MPD Mar 28 22:23:42 volumio go-librespot[11856]: time="2026-03-28T22:23:42Z" level=info msg="zeroconf server listening on port 38315" Mar 28 22:23:42 volumio volumio[11774]: info: Output device has changed, restarting Shairport Sync Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio sudo[11909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:42 volumio sudo[11913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:42 volumio sudo[11913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio sudo[11909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio volumio[11774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:42 volumio volumio[11774]: info: ___________ START PLUGINS ___________ Mar 28 22:23:42 volumio sudo[11909]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:42 volumio volumio[11774]: info: ControllerMpd::onStart: Initializing MPD Mar 28 22:23:42 volumio volumio[11774]: info: Creating MPD Configuration file Mar 28 22:23:42 volumio volumio[11864]: Starting albumart workers Mar 28 22:23:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:42 volumio volumio[11774]: info: [1774736622411] CoreMusicLibrary::Adding element Media Servers Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio volumio[11863]: Starting albumart workers Mar 28 22:23:42 volumio volumio[11774]: info: UPNP Browser: Client initialized successfully Mar 28 22:23:42 volumio sudo[11921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:42 volumio sudo[11921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio sudo[11921]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:42 volumio sudo[11923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:42 volumio sudo[11923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio volumio[11862]: Starting albumart workers Mar 28 22:23:42 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:42 volumio volumio[11774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:42 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:42 volumio volumio[11774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:42 volumio volumio[11774]: info: [1774736622486] CoreMusicLibrary::Adding element Last_100 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:42 volumio volumio[11774]: info: [1774736622488] CoreMusicLibrary::Adding element Webradio Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:42 volumio volumio[11774]: info: Initializing BBC Radios Mar 28 22:23:42 volumio sudo[11937]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:23:42 volumio sudo[11937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: Creating Spotify config file Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio sudo[11937]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:42 volumio volumio[11774]: info: [1774736622731] CoreMusicLibrary::Adding element YouTube Music Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio volumio[11774]: Cannot find translation for source YouTube Music Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:42 volumio volumio[11774]: info: [1774736622735] CoreMusicLibrary::Adding element Podcast Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio volumio[11774]: Cannot find translation for source YouTube Music Mar 28 22:23:42 volumio volumio[11774]: Cannot find translation for source Podcast Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Starting plugin Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 28 22:23:42 volumio volumio[11774]: info: Volumio Calling Home Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Database loaded at: 2026-03-28T22:23:42.779Z Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:42 volumio volumio[11774]: info: [1774736622812] CoreMusicLibrary::Adding element FM/DAB Radio Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:42 volumio volumio[11774]: Cannot find translation for source YouTube Music Mar 28 22:23:42 volumio volumio[11774]: Cannot find translation for source Podcast Mar 28 22:23:42 volumio volumio[11774]: Cannot find translation for source FM/DAB Radio Mar 28 22:23:42 volumio volumio[11774]: info: [RTL-SDR Radio] Plugin started successfully Mar 28 22:23:42 volumio volumio[11774]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:23:42 volumio volumio[11774]: info: Discovery: Found device Volumio Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio volumio[11774]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:23:42 volumio volumio[11774]: info: Discovery: Found device Volumio Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio volumio[11774]: info: MPD Permissions set Mar 28 22:23:42 volumio volumio[11774]: info: MPD Permissions set Mar 28 22:23:42 volumio volumio[11774]: info: Spotify config file written Mar 28 22:23:42 volumio go-librespot[11856]: time="2026-03-28T22:23:42Z" level=debug msg="obtained new client token: AABb4TBg3lnFvuDQGT84pMb3yAB/NM4Sf48AVjcBjszuO3IGA3iD9WOU5fTxiIX7S1MqchZ+rbNoycR79FUTQKq19BQXFxTKxHNI/9fD+xLSyjGgewDn0mRsIPVQ72VdTlkv0onte7BCzZDdcqqGimfgPl5hOpkG9dvdbv+vbcm+jJsm0zORgyLKuxkhtqoKtSudJP0U51R6M8Pk4N00qxoHlYDPLUwDiUuhhWvzkR430KVsPVxGBTltgQ==" Mar 28 22:23:42 volumio sudo[11979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:23:42 volumio sudo[11979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio volumio[11774]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:23:42 volumio systemd[1]: go-librespot-daemon.service: Killing process 11861 (go-librespot) with signal SIGKILL. Mar 28 22:23:42 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:23:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:42 volumio volumio[11774]: info: No need to fix Spotify hosts Mar 28 22:23:42 volumio volumio[11774]: info: Starting Shairport Sync Mar 28 22:23:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:42 volumio go-librespot[11991]: go-librespot daemon starting... Mar 28 22:23:42 volumio sudo[11979]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:42 volumio volumio[11774]: info: Starting Shairport Sync Mar 28 22:23:42 volumio go-librespot[11993]: time="2026-03-28T22:23:42Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:42 volumio go-librespot[11993]: time="2026-03-28T22:23:42Z" level=debug msg="app state loaded" Mar 28 22:23:42 volumio volumio[11774]: info: Starting Shairport Sync Mar 28 22:23:42 volumio go-librespot[11993]: time="2026-03-28T22:23:42Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:42 volumio sudo[11994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:42 volumio sudo[12003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:42 volumio sudo[12003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio sudo[11994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio sudo[12001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:23:42 volumio sudo[12001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:42 volumio volumio[11774]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:42 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:23:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:23:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:23:42 volumio systemd[1]: shairport-sync.service: Consumed 1.554s CPU time. Mar 28 22:23:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:23:43 volumio sudo[12001]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:43 volumio sudo[11994]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:43 volumio volumio[11774]: info: Shairport-Sync Started Mar 28 22:23:43 volumio sudo[12003]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:43 volumio volumio[11774]: Error adding Membership: Error: addMembership EINVAL Mar 28 22:23:43 volumio volumio[11774]: info: Shairport-Sync Started Mar 28 22:23:43 volumio volumio[11774]: info: Shairport-Sync Started Mar 28 22:23:43 volumio volumio[11774]: info: Volumio called home Mar 28 22:23:43 volumio mpd[11952]: 2026-03-28T22:23:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 22:23:43 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 28 22:23:43 volumio sudo[11913]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:43 volumio sudo[11923]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:43 volumio volumio[11774]: info: Completed starting Core Plugins Mar 28 22:23:43 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:43 volumio volumio[11774]: info: ----- MyVolumio plugins startup ---- Mar 28 22:23:43 volumio volumio[11774]: info: ------------------------------------------- Mar 28 22:23:43 volumio volumio[11774]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 28 22:23:43 volumio volumio[11774]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:23:43 volumio volumio[11774]: assert.ok(self.idling) Mar 28 22:23:43 volumio volumio[11774]: error: The expression evaluated to a falsy value: Mar 28 22:23:43 volumio volumio[11774]: assert.ok(self.idling) Mar 28 22:23:43 volumio volumio[11774]: info: MPD running with PID11952 Mar 28 22:23:43 volumio volumio[11774]: ,establishing connection Mar 28 22:23:43 volumio volumio[11774]: error: updateQueue error: null Mar 28 22:23:43 volumio volumio[11774]: error: updateQueue error: null Mar 28 22:23:43 volumio go-librespot[11993]: time="2026-03-28T22:23:43Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:43 volumio go-librespot[11993]: time="2026-03-28T22:23:43Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:43 volumio go-librespot[11993]: time="2026-03-28T22:23:43Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:43 volumio go-librespot[11993]: time="2026-03-28T22:23:43Z" level=info msg="zeroconf server listening on port 40669" Mar 28 22:23:43 volumio volumio[11774]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 28 22:23:43 volumio go-librespot[11993]: time="2026-03-28T22:23:43Z" level=debug msg="obtained new client token: AAB/x1rPFtLzD9zV9Z5MV3nOaqQhuQwYTKway9TslDbv5cgo0j4OCNG83qOO90XInD8yArNSM9/MXyFe1ElqGku1pZbLLoDpS3VdKquBoo0jdoVMPHf3+0v/MY3+ayy4IbetcH3gobh5pPjws6lEzTFz0ttonQqqRbij2dj0yUS9PVQHhwV3kuc1VesBXpQwww59VX80L6XpRbyiHR/lE1HrtqY5DeG9yeUJRAzkdeR+bxYxvgo/fgAgGQ==" Mar 28 22:23:44 volumio volumio-remote-updater[945]: [2026-03-28 22:23:44] [connect] Successful connection Mar 28 22:23:44 volumio volumio-remote-updater[945]: [2026-03-28 22:23:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774736624 101 Mar 28 22:23:44 volumio volumio[11774]: 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: 2 Mar 28 22:23:44 volumio sudo[11813]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:44 volumio go-librespot[11993]: time="2026-03-28T22:23:44Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:44 volumio go-librespot[11993]: time="2026-03-28T22:23:44Z" level=debug msg="completed keyexchange" Mar 28 22:23:44 volumio go-librespot[11993]: time="2026-03-28T22:23:44Z" level=debug msg="completed challenge" Mar 28 22:23:44 volumio go-librespot[11993]: time="2026-03-28T22:23:44Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:45 volumio go-librespot[11993]: time="2026-03-28T22:23:45Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:45 volumio go-librespot[11993]: time="2026-03-28T22:23:45Z" level=debug msg="completed keyexchange" Mar 28 22:23:45 volumio go-librespot[11993]: time="2026-03-28T22:23:45Z" level=debug msg="completed challenge" Mar 28 22:23:45 volumio go-librespot[11993]: time="2026-03-28T22:23:45Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:45 volumio volumio[11774]: info: go-librespot daemon successfully initialized Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=debug msg="completed keyexchange" Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=debug msg="completed challenge" Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=debug msg="completed keyexchange" Mar 28 22:23:46 volumio go-librespot[11993]: time="2026-03-28T22:23:46Z" level=debug msg="completed challenge" Mar 28 22:23:47 volumio go-librespot[11993]: time="2026-03-28T22:23:47Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:47 volumio go-librespot[11993]: time="2026-03-28T22:23:47Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:23:47 volumio go-librespot[11993]: time="2026-03-28T22:23:47Z" level=debug msg="completed keyexchange" Mar 28 22:23:47 volumio go-librespot[11993]: time="2026-03-28T22:23:47Z" level=debug msg="completed challenge" Mar 28 22:23:47 volumio go-librespot[11993]: time="2026-03-28T22:23:47Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:48 volumio go-librespot[11993]: time="2026-03-28T22:23:48Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 28 22:23:48 volumio go-librespot[11993]: time="2026-03-28T22:23:48Z" level=debug msg="completed keyexchange" Mar 28 22:23:48 volumio go-librespot[11993]: time="2026-03-28T22:23:48Z" level=debug msg="completed challenge" Mar 28 22:23:48 volumio go-librespot[11993]: time="2026-03-28T22:23:48Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:48 volumio go-librespot[11993]: time="2026-03-28T22:23:48Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:48 volumio volumio[11774]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:48 volumio volumio[11774]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:23:50 volumio sudo[12045]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:50 volumio sudo[12045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:50 volumio sudo[12047]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:50 volumio sudo[12045]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:50 volumio sudo[12047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:50 volumio sudo[12047]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:50 volumio sudo[12051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 28 22:23:50 volumio sudo[12051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:50 volumio sudo[12051]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:50 volumio volumio[11774]: info: Upmpdcli Daemon Started Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 22:23:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 28 22:23:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:51 volumio go-librespot[12054]: go-librespot daemon starting... Mar 28 22:23:51 volumio go-librespot[12055]: time="2026-03-28T22:23:51Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:51 volumio go-librespot[12055]: time="2026-03-28T22:23:51Z" level=debug msg="app state loaded" Mar 28 22:23:51 volumio go-librespot[12055]: time="2026-03-28T22:23:51Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 22:23:51 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:51 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:51 volumio volumio[11774]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 22:23:51 volumio volumio[11774]: info: MyVolumio login type: Token Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 22:23:51 volumio volumio[11774]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=info msg="zeroconf server listening on port 42405" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="obtained new client token: AACvyVneMuG15zTAQmUp+sCZFLp/CPsqRooWsV1pitc8W3fnAEraMA+v7Mhp38f5b87SOzG2/4dDLVGdWo+iTax3ka57iyJIWldLp9g0mEbNT/7VNBZg95UzwPw+9JtTjBQSd9ZnsBuvaeO/J/XZjD/9cmsWW1H/PS9trBE0ifOEf4nu5hralRRvqhtTILFMH+AWuPc+pmikEfSWajiyr5MDWhRt0UIAL+egpgKMwZD/9ufwQoZEDJA=" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:23:52 volumio volumio[11774]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="completed keyexchange" Mar 28 22:23:52 volumio volumio[11774]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="completed challenge" Mar 28 22:23:52 volumio volumio[11774]: info: Streaming services startup Mar 28 22:23:52 volumio volumio[11774]: info: Starting Streaming Daemon Mar 28 22:23:52 volumio sudo[12065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:52 volumio sudo[12065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:52 volumio volumio[11774]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:52 volumio volumio[11774]: info: Initializing connection to go-librespot Websocket Mar 28 22:23:52 volumio sudo[12065]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:52 volumio volumio[11774]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:52 volumio volumio[11774]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:52 volumio volumio[11774]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="new websocket client" Mar 28 22:23:52 volumio volumio[11774]: info: Connection to go-librespot Websocket established Mar 28 22:23:52 volumio volumio[11774]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="completed keyexchange" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=debug msg="completed challenge" Mar 28 22:23:52 volumio go-librespot[12055]: time="2026-03-28T22:23:52Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:52 volumio volumio[11774]: info: MyVolumio token set successfully Mar 28 22:23:52 volumio volumio[11774]: info: MYVOLUMIO: Adding device Mar 28 22:23:52 volumio volumio[11774]: info: MYVOLUMIO: Evaluating Server Mar 28 22:23:53 volumio volumio[11774]: info: MyVolumio status changed Mar 28 22:23:53 volumio volumio[11774]: info: Streaming services startup Mar 28 22:23:53 volumio volumio[11774]: info: Starting Streaming Daemon Mar 28 22:23:53 volumio volumio[11774]: info: Removing browser output: myVolumio user plan is not superstar Mar 28 22:23:53 volumio volumio[11774]: info: Removing audio output: Mar 28 22:23:53 volumio volumio[11774]: info: Stoppping Tunnel 1 Mar 28 22:23:53 volumio sudo[12092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:23:53 volumio sudo[12092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:53 volumio sudo[12094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 28 22:23:53 volumio sudo[12094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 22:23:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 22:23:53 volumio sudo[12092]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 22:23:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 22:23:53 volumio volumio[11774]: error: Cannot start Volumio Streaming Daemon Mar 28 22:23:53 volumio volumio[11774]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:23:53 volumio volumio[11774]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:23:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 22:23:53 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 22:23:53 volumio sudo[12094]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:53 volumio volumio[11774]: info: Remote SSH Stopped Mar 28 22:23:53 volumio go-librespot[12055]: time="2026-03-28T22:23:53Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:23:53 volumio go-librespot[12055]: time="2026-03-28T22:23:53Z" level=debug msg="completed keyexchange" Mar 28 22:23:53 volumio go-librespot[12055]: time="2026-03-28T22:23:53Z" level=debug msg="completed challenge" Mar 28 22:23:53 volumio go-librespot[12055]: time="2026-03-28T22:23:53Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:53 volumio volumio[11774]: info: Setting Geolocation for MyVolumio to eu2 Mar 28 22:23:53 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:53 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:53 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:53 volumio volumio[11774]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 28 22:23:54 volumio go-librespot[12055]: time="2026-03-28T22:23:54Z" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Mar 28 22:23:54 volumio go-librespot[12055]: time="2026-03-28T22:23:54Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:23:54 volumio go-librespot[12055]: time="2026-03-28T22:23:54Z" level=debug msg="completed keyexchange" Mar 28 22:23:54 volumio go-librespot[12055]: time="2026-03-28T22:23:54Z" level=debug msg="completed challenge" Mar 28 22:23:54 volumio go-librespot[12055]: time="2026-03-28T22:23:54Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:54 volumio volumio[11774]: info: Updating MyVolumio device info Mar 28 22:23:54 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:54 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:54 volumio volumio[11774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:54 volumio volumio[11774]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 28 22:23:54 volumio go-librespot[12055]: time="2026-03-28T22:23:54Z" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=debug msg="completed keyexchange" Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=debug msg="completed challenge" Mar 28 22:23:55 volumio volumio[11774]: info: Getting Spotify volume Mar 28 22:23:55 volumio volumio[11774]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 28 22:23:55 volumio volumio[11774]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:55 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:55 volumio volumio[11774]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 28 22:23:55 volumio volumio[11774]: SPOTIFY: SPOTIFY VOLUME undefined Mar 28 22:23:55 volumio volumio[11774]: SPOTIFY: VOLUMIO VOLUME 0 Mar 28 22:23:55 volumio volumio[11774]: info: Aligning Spotify Volume to Volumio Volume Mar 28 22:23:55 volumio volumio[11774]: info: CoreCommandRouter::volumioGetState Mar 28 22:23:55 volumio volumio[11774]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:55 volumio volumio[11774]: info: Setting Spotify Volume from Volumio: 0 Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=debug msg="completed keyexchange" Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=debug msg="completed challenge" Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:55 volumio go-librespot[12055]: time="2026-03-28T22:23:55Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:23:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:23:55 volumio volumio[11774]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:55 volumio volumio[11774]: Error: socket hang up Mar 28 22:23:55 volumio volumio[11774]: at connResetException (node:internal/errors:720:14) Mar 28 22:23:55 volumio volumio[11774]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 28 22:23:55 volumio volumio[11774]: at Socket.emit (node:events:526:35) Mar 28 22:23:55 volumio volumio[11774]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 28 22:23:55 volumio volumio[11774]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 28 22:23:55 volumio volumio[11774]: code: 'ECONNRESET', Mar 28 22:23:55 volumio volumio[11774]: response: undefined Mar 28 22:23:55 volumio volumio[11774]: } Mar 28 22:23:55 volumio volumio[11774]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:23:56 volumio sudo[12111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:22' Mar 28 22:23:56 volumio sudo[12111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:56 volumio sudo[12111]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:56 volumio volumio-remote-updater[945]: [2026-03-28 22:23:56] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 28 22:23:56 volumio volumio-remote-updater[945]: [2026-03-28 22:23:56] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 28 22:23:56 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:23:56 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 28 22:23:56 volumio systemd[1]: volumio.service: Consumed 8.958s CPU time. Mar 28 22:23:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:56 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 87504. Mar 28 22:23:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 28 22:23:56 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 28 22:23:56 volumio systemd[1]: volumio.service: Consumed 8.958s CPU time. Mar 28 22:23:56 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 28 22:23:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 28 22:23:57 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:23:57 volumio volumio[12130]: info: ----- Volumio3 ---- Mar 28 22:23:57 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:23:57 volumio volumio[12130]: info: ----- System startup ---- Mar 28 22:23:57 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:23:57 volumio volumio[12130]: info: MYVOLUMIO Environment detected Mar 28 22:23:57 volumio volumio[12130]: info: Plugin folders cleanup Mar 28 22:23:57 volumio volumio[12130]: info: Scanning into folder /volumio/app/plugins/ Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category audio_interface Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category miscellanea Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category music_service Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category plugins.json Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category system_controller Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category user_interface Mar 28 22:23:57 volumio volumio[12130]: info: Scanning into folder /data/plugins/ Mar 28 22:23:57 volumio volumio[12130]: info: Scanning category music_service Mar 28 22:23:57 volumio volumio[12130]: info: Plugin folders cleanup completed Mar 28 22:23:57 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:23:57 volumio volumio[12130]: info: ----- Core plugins startup ---- Mar 28 22:23:57 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugins from folder /volumio/app/plugins/ Mar 28 22:23:57 volumio volumio[12130]: info: Adding plugin upnp to MyMusic Plugins Mar 28 22:23:57 volumio volumio[12130]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 28 22:23:57 volumio volumio[12130]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugins from folder /data/plugins/ Mar 28 22:23:57 volumio volumio[12130]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "system"... Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "appearance"... Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "network"... Mar 28 22:23:57 volumio volumio[12130]: info: Refreshing Cached IP Addresses Mar 28 22:23:57 volumio sudo[12158]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:23:57 volumio sudo[12158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:57 volumio sudo[12160]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:23:57 volumio sudo[12158]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:57 volumio sudo[12160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "services"... Mar 28 22:23:57 volumio sudo[12160]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "alsa_controller"... Mar 28 22:23:57 volumio sudo[12168]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 28 22:23:57 volumio sudo[12168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:57 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "wizard"... Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "networkfs"... Mar 28 22:23:57 volumio volumio[12130]: info: Starting Udev Watcher for removable devices Mar 28 22:23:57 volumio volumio[12130]: info: Mounting Device 0ACB-A1DE Mar 28 22:23:57 volumio sudo[12197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:57 volumio sudo[12197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:57 volumio sudo[12197]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:57 volumio volumio[12130]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:57 volumio volumio[12130]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:57 volumio volumio[12130]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 28 22:23:57 volumio volumio[12130]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Mar 28 22:23:57 volumio volumio[12130]: dmesg(1) may have more information after failed mount system call. Mar 28 22:23:57 volumio volumio[12130]: info: Ignoring mount for partition: boot Mar 28 22:23:57 volumio volumio[12130]: info: Ignoring mount for partition: volumio Mar 28 22:23:57 volumio volumio[12130]: info: Ignoring mount for partition: volumio_data Mar 28 22:23:57 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "volumio_command_line_client"... Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "upnp"... Mar 28 22:23:57 volumio volumio[12130]: info: [1774736637868] Starting Upmpd Daemon Mar 28 22:23:57 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "my_music"... Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "mpd"... Mar 28 22:23:57 volumio volumio[12130]: info: Loading plugin "upnp_browser"... Mar 28 22:23:58 volumio volumio[12130]: info: Starting UPNP Browser Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "alarm-clock"... Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "airplay_emulation"... Mar 28 22:23:58 volumio volumio[12130]: info: Starting Shairport Sync Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "last_100"... Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "webradio"... Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "i2s_dacs"... Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "volumiodiscovery"... Mar 28 22:23:58 volumio volumio[12130]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:58 volumio volumio[12130]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:58 volumio volumio[12130]: *** WARNING *** For more information see Mar 28 22:23:58 volumio volumio[12130]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:58 volumio volumio[12130]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:58 volumio volumio[12130]: *** WARNING *** For more information see Mar 28 22:23:58 volumio node[12130]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:58 volumio node[12130]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:58 volumio node[12130]: *** WARNING *** For more information see Mar 28 22:23:58 volumio node[12130]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 22:23:58 volumio node[12130]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 22:23:58 volumio node[12130]: *** WARNING *** For more information see Mar 28 22:23:58 volumio volumio[12130]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 28 22:23:58 volumio volumio[12130]: info: Discovery: Started advertising with name: Volumio Mar 28 22:23:58 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "spop"... Mar 28 22:23:58 volumio volumio[12130]: info: Loading plugin "ytmusic"... Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "outputs"... Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "albumart"... Mar 28 22:23:59 volumio volumio[12130]: info: Plugin example_plugin is not enabled Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "inputs"... Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "updater_comm"... Mar 28 22:23:59 volumio volumio[12130]: info: Plugin mpdemulation is not enabled Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "rest_api"... Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "websocket"... Mar 28 22:23:59 volumio volumio[12130]: info: Starting Socket.io Server version 1.7.4 Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "podcast"... Mar 28 22:23:59 volumio volumio[12130]: info: ControllerPodcast::constructor Mar 28 22:23:59 volumio volumio[12130]: info: Loading plugin "rtlsdr_radio"... Mar 28 22:23:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 28 22:23:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:59 volumio volumio[12201]: Forking 3 albumart workers Mar 28 22:23:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:23:59 volumio go-librespot[12211]: go-librespot daemon starting... Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=debug msg="app state loaded" Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:23:59 volumio volumio[12130]: info: Loading i18n strings for locale en Mar 28 22:23:59 volumio volumio[12130]: Updating browse sources language Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::initPlayerControls Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: Express server listening on port 3000 Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=info msg="zeroconf server listening on port 34249" Mar 28 22:23:59 volumio volumio[12130]: [Metrics] WebUI: 2s 350.99ms Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::resetVolumioState Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::getcurrentVolume Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:59 volumio volumio[12130]: info: Volumio Network Manager: Network status updated: 2 Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: Reloading queue from file Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::setRepeat null single undefined Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::pushState Mar 28 22:23:59 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::setRandom true Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::pushState Mar 28 22:23:59 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:59 volumio volumio[12130]: info: Setting Device type: Raspberry PI Mar 28 22:23:59 volumio volumio[12130]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 28 22:23:59 volumio volumio[12130]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Mar 28 22:23:59 volumio volumio[12130]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 28 22:23:59 volumio volumio[12130]: info: Completed loading Core Plugins Mar 28 22:23:59 volumio volumio[12130]: info: Preparing to generate the ALSA configuration file Mar 28 22:23:59 volumio volumio[12130]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::pushState Mar 28 22:23:59 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioPushState Mar 28 22:23:59 volumio volumio[12130]: info: CoreStateMachine::updateTrackBlock Mar 28 22:23:59 volumio volumio[12130]: info: CorePlayQueue::getTrackBlock Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 22:23:59 volumio volumio[12130]: info: Asound.conf file unchanged, so no further update is needed Mar 28 22:23:59 volumio volumio[12130]: info: Output device has changed, restarting MPD Mar 28 22:23:59 volumio volumio[12130]: info: Output device has changed, restarting Shairport Sync Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:59 volumio sudo[12268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:59 volumio sudo[12268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:59 volumio sudo[12268]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:59 volumio sudo[12270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:59 volumio sudo[12270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:59 volumio volumio[12130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:59 volumio volumio[12130]: info: ___________ START PLUGINS ___________ Mar 28 22:23:59 volumio volumio[12219]: Starting albumart workers Mar 28 22:23:59 volumio volumio[12130]: info: ControllerMpd::onStart: Initializing MPD Mar 28 22:23:59 volumio volumio[12130]: info: Creating MPD Configuration file Mar 28 22:23:59 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:59 volumio volumio[12130]: info: [1774736639630] CoreMusicLibrary::Adding element Media Servers Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:59 volumio sudo[12278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:23:59 volumio sudo[12278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:59 volumio sudo[12280]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:23:59 volumio volumio[12130]: info: UPNP Browser: Client initialized successfully Mar 28 22:23:59 volumio sudo[12280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:23:59 volumio sudo[12278]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:59 volumio volumio[12220]: Starting albumart workers Mar 28 22:23:59 volumio volumio[12130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:59 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:23:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:23:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:23:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:23:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:23:59 volumio volumio[12130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:59 volumio volumio[12130]: info: [1774736639681] CoreMusicLibrary::Adding element Last_100 Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:59 volumio volumio[12130]: info: [1774736639686] CoreMusicLibrary::Adding element Webradio Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:59 volumio volumio[12130]: info: Initializing BBC Radios Mar 28 22:23:59 volumio volumio[12218]: Starting albumart workers Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:23:59 volumio sudo[12292]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:23:59 volumio sudo[12292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:23:59 volumio volumio[12130]: info: Creating Spotify config file Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:23:59 volumio sudo[12292]: pam_unix(sudo:session): session closed for user root Mar 28 22:23:59 volumio go-librespot[12212]: time="2026-03-28T22:23:59Z" level=debug msg="obtained new client token: AAC2gZqhPVTa6EGxeQ/CWNbpLNEEvtITcMnvgeMbAqJcEw4weFOyD/SdH5uYldcizWP4I8jkqjd/2PyGOWuPN0sUol2SlU0qvJDnUwQ9CcLID6oSWDJp3h1bb75ctvfsubEqvO4no/dxCw0gl1cY030zSf0NhpZzW+htUT26nTajUx77JbE+JVXu3Yj3D3nOgW6A8+LThGL2imEqu0lyWHXWxcnFx+SFdahgIRAIJR5thKJf/RPH3LLlvA==" Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:59 volumio volumio[12130]: info: [1774736639933] CoreMusicLibrary::Adding element YouTube Music Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:59 volumio volumio[12130]: Cannot find translation for source YouTube Music Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:23:59 volumio volumio[12130]: info: [1774736639939] CoreMusicLibrary::Adding element Podcast Mar 28 22:23:59 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:23:59 volumio volumio[12130]: Cannot find translation for source YouTube Music Mar 28 22:23:59 volumio volumio[12130]: Cannot find translation for source Podcast Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Starting plugin Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Mar 28 22:23:59 volumio volumio[12130]: info: Volumio Calling Home Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] snd-aloop already loaded Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] No stations database found, creating v2 Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Database loaded at: 2026-03-28T22:23:59.988Z Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Got 21 phrases from file Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Updated metadata blocklist Mar 28 22:23:59 volumio volumio[12130]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Mar 28 22:24:00 volumio volumio[12130]: info: [RTL-SDR Radio] Management server started on port 3456 Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 22:24:00 volumio volumio[12130]: info: [1774736640025] CoreMusicLibrary::Adding element FM/DAB Radio Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:24:00 volumio volumio[12130]: Cannot find translation for source YouTube Music Mar 28 22:24:00 volumio volumio[12130]: Cannot find translation for source Podcast Mar 28 22:24:00 volumio volumio[12130]: Cannot find translation for source FM/DAB Radio Mar 28 22:24:00 volumio volumio[12130]: info: [RTL-SDR Radio] Plugin started successfully Mar 28 22:24:00 volumio volumio[12130]: info: MPD Permissions set Mar 28 22:24:00 volumio volumio[12130]: info: MPD Permissions set Mar 28 22:24:00 volumio volumio[12130]: info: VolumeController:: Volume=36 Mute =true Mar 28 22:24:00 volumio volumio[12130]: info: CoreStateMachine::pushState Mar 28 22:24:00 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::volumioPushState Mar 28 22:24:00 volumio volumio[12130]: info: Spotify config file written Mar 28 22:24:00 volumio sudo[12335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:24:00 volumio sudo[12335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:00 volumio go-librespot[12212]: time="2026-03-28T22:24:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:24:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:24:00 volumio volumio[12130]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 28 22:24:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:24:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:24:00 volumio volumio[12130]: info: No need to fix Spotify hosts Mar 28 22:24:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:24:00 volumio go-librespot[12337]: go-librespot daemon starting... Mar 28 22:24:00 volumio sudo[12335]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=debug msg="app state loaded" Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:24:00 volumio volumio[12130]: info: Starting Shairport Sync Mar 28 22:24:00 volumio volumio[12130]: info: Starting Shairport Sync Mar 28 22:24:00 volumio volumio[12130]: info: Starting Shairport Sync Mar 28 22:24:00 volumio sudo[12355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:24:00 volumio sudo[12355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:00 volumio sudo[12358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:24:00 volumio sudo[12358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:00 volumio sudo[12359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:24:00 volumio sudo[12359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:24:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:24:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:24:00 volumio systemd[1]: shairport-sync.service: Consumed 1.555s CPU time. Mar 28 22:24:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:24:00 volumio sudo[12355]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:00 volumio volumio[12130]: info: Shairport-Sync Started Mar 28 22:24:00 volumio volumio[12130]: Error adding Membership: Error: addMembership EINVAL Mar 28 22:24:00 volumio sudo[12359]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:00 volumio volumio[12130]: info: Shairport-Sync Started Mar 28 22:24:00 volumio sudo[12358]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:00 volumio volumio[12130]: info: Shairport-Sync Started Mar 28 22:24:00 volumio volumio[12130]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:24:00 volumio volumio[12130]: info: Discovery: Found device Volumio Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::volumioGetState Mar 28 22:24:00 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::volumioGetState Mar 28 22:24:00 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:24:00 volumio volumio[12130]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Mar 28 22:24:00 volumio volumio[12130]: info: Discovery: Found device Volumio Mar 28 22:24:00 volumio volumio[12130]: info: CoreCommandRouter::volumioGetState Mar 28 22:24:00 volumio volumio[12130]: info: CorePlayQueue::getTrack 0 Mar 28 22:24:00 volumio volumio[12130]: info: Volumio called home Mar 28 22:24:00 volumio mpd[12307]: 2026-03-28T22:24:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 22:24:00 volumio volumio[12130]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 28 22:24:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 28 22:24:00 volumio sudo[12270]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:00 volumio sudo[12280]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:00 volumio volumio[12130]: error: updateQueue error: null Mar 28 22:24:00 volumio volumio[12130]: info: Completed starting Core Plugins Mar 28 22:24:00 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:24:00 volumio volumio[12130]: info: ----- MyVolumio plugins startup ---- Mar 28 22:24:00 volumio volumio[12130]: info: ------------------------------------------- Mar 28 22:24:00 volumio volumio[12130]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 28 22:24:00 volumio volumio[12130]: error: updateQueue error: null Mar 28 22:24:00 volumio volumio[12130]: info: MPD running with PID12307 Mar 28 22:24:00 volumio volumio[12130]: ,establishing connection Mar 28 22:24:00 volumio volumio[12130]: error: updateQueue error: null Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=info msg="zeroconf server listening on port 42629" Mar 28 22:24:00 volumio go-librespot[12348]: time="2026-03-28T22:24:00Z" level=debug msg="obtained new client token: AADYaSq1e4CzVAM7MmcqN29adIJApUjT5Y29B8a6GhSAv0Rogo/Gd2ykhVp6dyve8QSwplazXhTpptaE1rdP/VZuK22mR90gVuAZ6d4OZB0JtwE+ScNLyYr+Y5y9Pa9oANdWFiEKawpsLA4DQrQBAg/hN0ERJ2eQKNu0iEUMfTBz+qKJmkzfjdg7kgda8GWPRK0FjwaMpCN71U2CRW7qjCe4azdO7QLbGD6yqYD+2ta7Li4qrUOOCg4RlA==" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=debug msg="completed keyexchange" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=debug msg="completed challenge" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:01 volumio volumio-remote-updater[945]: [2026-03-28 22:24:01] [connect] Successful connection Mar 28 22:24:01 volumio volumio-remote-updater[945]: [2026-03-28 22:24:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774736641 101 Mar 28 22:24:01 volumio volumio[12130]: 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: 2 Mar 28 22:24:01 volumio sudo[12168]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=debug msg="completed keyexchange" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=debug msg="completed challenge" Mar 28 22:24:01 volumio go-librespot[12348]: time="2026-03-28T22:24:01Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:02 volumio go-librespot[12348]: time="2026-03-28T22:24:02Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:24:02 volumio go-librespot[12348]: time="2026-03-28T22:24:02Z" level=debug msg="completed keyexchange" Mar 28 22:24:02 volumio go-librespot[12348]: time="2026-03-28T22:24:02Z" level=debug msg="completed challenge" Mar 28 22:24:02 volumio go-librespot[12348]: time="2026-03-28T22:24:02Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:03 volumio volumio[12130]: info: go-librespot daemon successfully initialized Mar 28 22:24:03 volumio go-librespot[12348]: time="2026-03-28T22:24:03Z" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 28 22:24:03 volumio go-librespot[12348]: time="2026-03-28T22:24:03Z" level=debug msg="completed keyexchange" Mar 28 22:24:03 volumio go-librespot[12348]: time="2026-03-28T22:24:03Z" level=debug msg="completed challenge" Mar 28 22:24:03 volumio go-librespot[12348]: time="2026-03-28T22:24:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=debug msg="completed keyexchange" Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=debug msg="completed challenge" Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Mar 28 22:24:04 volumio go-librespot[12348]: time="2026-03-28T22:24:04Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:24:05 volumio go-librespot[12348]: time="2026-03-28T22:24:05Z" level=debug msg="completed keyexchange" Mar 28 22:24:05 volumio go-librespot[12348]: time="2026-03-28T22:24:05Z" level=debug msg="completed challenge" Mar 28 22:24:05 volumio go-librespot[12348]: time="2026-03-28T22:24:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:05 volumio go-librespot[12348]: time="2026-03-28T22:24:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:24:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:24:06 volumio volumio[12130]: info: Initializing connection to go-librespot Websocket Mar 28 22:24:06 volumio volumio[12130]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:24:07 volumio sudo[12401]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 22:24:07 volumio sudo[12401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:07 volumio sudo[12401]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:07 volumio sudo[12403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 22:24:07 volumio sudo[12403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:07 volumio sudo[12405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 28 22:24:07 volumio sudo[12405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:07 volumio sudo[12403]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:07 volumio sudo[12405]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:07 volumio volumio[12130]: info: Upmpdcli Daemon Started Mar 28 22:24:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 28 22:24:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:24:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:24:08 volumio go-librespot[12409]: go-librespot daemon starting... Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=info msg="running go-librespot 0.6.2" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="app state loaded" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=info msg="zeroconf server listening on port 36607" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="obtained new client token: AADYa16yw2xtA70clmzHQWZE1KwvlOxOu7ExuFIINb8vnnC4lB9IHff7hkVZMyJcWqw4/pj38bd8aJINNQm3ePRfT3uv2tQFObjYup1exc07WMtWzGB49g26CH58PxlDxCokxLA/4qOz38NyojohtJQPHMP5Y0afwjVzhyT/IBRZ9+wESfLE/7veibQnA8QA6qZzvpwULPXwDOVp2bAB5JeXVRtSt9cSDXVhgy+zZ1TEtEpJEMIC+NAj5A==" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="completed keyexchange" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=debug msg="completed challenge" Mar 28 22:24:08 volumio go-librespot[12410]: time="2026-03-28T22:24:08Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="connected to ap-gew1.spotify.com:443" Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="completed keyexchange" Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="completed challenge" Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 22:24:09 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:09 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:09 volumio volumio[12130]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 22:24:09 volumio volumio[12130]: info: MyVolumio login type: Token Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 22:24:09 volumio volumio[12130]: info: Streaming services startup Mar 28 22:24:09 volumio volumio[12130]: info: Starting Streaming Daemon Mar 28 22:24:09 volumio sudo[12420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:24:09 volumio sudo[12420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:09 volumio volumio[12130]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 22:24:09 volumio sudo[12420]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:09 volumio volumio[12130]: info: Initializing connection to go-librespot Websocket Mar 28 22:24:09 volumio volumio[12130]: error: Cannot start Volumio Streaming Daemon Mar 28 22:24:09 volumio volumio[12130]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:24:09 volumio volumio[12130]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="new websocket client" Mar 28 22:24:09 volumio volumio[12130]: info: Connection to go-librespot Websocket established Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="connected to ap-gew1.spotify.com:80" Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="completed keyexchange" Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=debug msg="completed challenge" Mar 28 22:24:09 volumio go-librespot[12410]: time="2026-03-28T22:24:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:10 volumio volumio[12130]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 28 22:24:10 volumio volumio[12130]: info: MyVolumio token set successfully Mar 28 22:24:10 volumio volumio[12130]: info: MYVOLUMIO: Adding device Mar 28 22:24:10 volumio volumio[12130]: info: MYVOLUMIO: Evaluating Server Mar 28 22:24:10 volumio go-librespot[12410]: time="2026-03-28T22:24:10Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:24:10 volumio volumio[12130]: info: MyVolumio status changed Mar 28 22:24:10 volumio volumio[12130]: info: Streaming services startup Mar 28 22:24:10 volumio volumio[12130]: info: Starting Streaming Daemon Mar 28 22:24:10 volumio volumio[12130]: info: Removing browser output: myVolumio user plan is not superstar Mar 28 22:24:10 volumio volumio[12130]: info: Removing audio output: Mar 28 22:24:10 volumio volumio[12130]: info: Stoppping Tunnel 1 Mar 28 22:24:10 volumio sudo[12447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 22:24:10 volumio sudo[12447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:10 volumio sudo[12449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 28 22:24:10 volumio sudo[12449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:24:10 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. Mar 28 22:24:10 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. Mar 28 22:24:10 volumio sudo[12447]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:10 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. Mar 28 22:24:10 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. Mar 28 22:24:10 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. Mar 28 22:24:10 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. Mar 28 22:24:10 volumio sudo[12449]: pam_unix(sudo:session): session closed for user root Mar 28 22:24:10 volumio volumio[12130]: error: Cannot start Volumio Streaming Daemon Mar 28 22:24:10 volumio volumio[12130]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 22:24:10 volumio volumio[12130]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 22:24:10 volumio volumio[12130]: info: Remote SSH Stopped Mar 28 22:24:10 volumio go-librespot[12410]: time="2026-03-28T22:24:10Z" level=debug msg="completed keyexchange" Mar 28 22:24:10 volumio go-librespot[12410]: time="2026-03-28T22:24:10Z" level=debug msg="completed challenge" Mar 28 22:24:10 volumio go-librespot[12410]: time="2026-03-28T22:24:10Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:10 volumio volumio[12130]: info: Setting Geolocation for MyVolumio to eu3 Mar 28 22:24:10 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:10 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:10 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:11 volumio volumio[12130]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 28 22:24:11 volumio go-librespot[12410]: time="2026-03-28T22:24:11Z" level=debug msg="connected to ap-gue1.spotify.com:443" Mar 28 22:24:11 volumio go-librespot[12410]: time="2026-03-28T22:24:11Z" level=debug msg="completed keyexchange" Mar 28 22:24:11 volumio go-librespot[12410]: time="2026-03-28T22:24:11Z" level=debug msg="completed challenge" Mar 28 22:24:11 volumio go-librespot[12410]: time="2026-03-28T22:24:11Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:11 volumio volumio[12130]: info: Updating MyVolumio device info Mar 28 22:24:11 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:11 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:11 volumio volumio[12130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:24:12 volumio go-librespot[12410]: time="2026-03-28T22:24:12Z" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 28 22:24:12 volumio go-librespot[12410]: time="2026-03-28T22:24:12Z" level=debug msg="completed keyexchange" Mar 28 22:24:12 volumio go-librespot[12410]: time="2026-03-28T22:24:12Z" level=debug msg="completed challenge" Mar 28 22:24:12 volumio volumio[12130]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 28 22:24:12 volumio go-librespot[12410]: time="2026-03-28T22:24:12Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:12 volumio go-librespot[12410]: time="2026-03-28T22:24:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 28 22:24:12 volumio volumio[12130]: info: Connection to go-librespot Websocket closed Mar 28 22:24:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 22:24:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 22:24:12 volumio volumio[12130]: info: Getting Spotify volume Mar 28 22:24:12 volumio volumio[12130]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:24:12 volumio volumio[12130]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:24:12 volumio volumio[12130]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 28 22:24:12 volumio volumio[12130]: errno: -111, Mar 28 22:24:12 volumio volumio[12130]: code: 'ECONNREFUSED', Mar 28 22:24:12 volumio volumio[12130]: syscall: 'connect', Mar 28 22:24:12 volumio volumio[12130]: address: '127.0.0.1', Mar 28 22:24:12 volumio volumio[12130]: port: 9879, Mar 28 22:24:12 volumio volumio[12130]: response: undefined Mar 28 22:24:12 volumio volumio[12130]: } Mar 28 22:24:12 volumio volumio[12130]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:24:12 volumio sudo[12467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:23' Mar 28 22:24:12 volumio sudo[12467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"