Feb 23 02:54:00 volumio go-librespot[9362]: time="2026-02-23T02:54:00Z" level=debug msg="completed keyexchange" Feb 23 02:54:00 volumio go-librespot[9362]: time="2026-02-23T02:54:00Z" level=debug msg="completed challenge" Feb 23 02:54:00 volumio go-librespot[9362]: time="2026-02-23T02:54:00Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:00 volumio go-librespot[9362]: time="2026-02-23T02:54:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:00 volumio volumio[9144]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:00 volumio volumio[9144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 02:54:02 volumio sudo[9416]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:02 volumio sudo[9416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:02 volumio sudo[9416]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:02 volumio sudo[9418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:02 volumio sudo[9418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:02 volumio sudo[9418]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:02 volumio sudo[9420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 02:54:02 volumio sudo[9420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:02 volumio sudo[9420]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:02 volumio volumio[9144]: info: Upmpdcli Daemon Started Feb 23 02:54:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 23 02:54:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:03 volumio go-librespot[9424]: go-librespot daemon starting... Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=debug msg="app state loaded" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" 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]" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" 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]" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" 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]" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=info msg="zeroconf server listening on port 39883" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=debug msg="obtained new client token: AABE37EDI+1W8LzRKlm0Ay0XJ2USpF4RmaSBJdIgZb1juZMWdF2p9ofGwhXGzwH7PqGOGLXi1xQS+sLBc+REVXY5YQLfm/Kc1wB03+RU9ln0IhoDypAp0Cm2n4jj2nI48lZZnhgorY+RJxilu5kOZPXCQd7/QUC9fmSrRCdeoxIYvi+qQHT89OVC5pUnv6jMosrRmb7OAO12+RTwa9IBQB3VRThL4aUIPPFwziXBlLK/FNZrU5WDGdn99w==" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=debug msg="completed keyexchange" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=debug msg="completed challenge" Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 02:54:03 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:03 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:03 volumio volumio[9144]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 02:54:03 volumio volumio[9144]: info: MyVolumio login type: Token Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 02:54:03 volumio volumio[9144]: info: Streaming services startup Feb 23 02:54:03 volumio volumio[9144]: info: Starting Streaming Daemon Feb 23 02:54:03 volumio sudo[9435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:03 volumio sudo[9435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:03 volumio volumio[9144]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 02:54:03 volumio sudo[9435]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:03 volumio volumio[9144]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:03 volumio volumio[9144]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:03 volumio volumio[9144]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:03 volumio volumio[9144]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:03 volumio volumio[9144]: info: Connection to go-librespot Websocket established Feb 23 02:54:03 volumio go-librespot[9425]: time="2026-02-23T02:54:03Z" level=debug msg="new websocket client" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=debug msg="completed keyexchange" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=debug msg="completed challenge" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:04 volumio volumio[9144]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=debug msg="completed keyexchange" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=debug msg="completed challenge" Feb 23 02:54:04 volumio go-librespot[9425]: time="2026-02-23T02:54:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:05 volumio volumio[9144]: info: MyVolumio token set successfully Feb 23 02:54:05 volumio volumio[9144]: info: MYVOLUMIO: Adding device Feb 23 02:54:05 volumio volumio[9144]: info: MYVOLUMIO: Evaluating Server Feb 23 02:54:05 volumio volumio[9144]: info: MyVolumio status changed Feb 23 02:54:05 volumio volumio[9144]: info: Streaming services startup Feb 23 02:54:05 volumio volumio[9144]: info: Starting Streaming Daemon Feb 23 02:54:05 volumio volumio[9144]: info: Removing browser output: myVolumio user plan is not superstar Feb 23 02:54:05 volumio volumio[9144]: info: Removing audio output: Feb 23 02:54:05 volumio volumio[9144]: info: Stoppping Tunnel 1 Feb 23 02:54:05 volumio sudo[9462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:05 volumio sudo[9462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:05 volumio sudo[9464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 23 02:54:05 volumio sudo[9464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:05 volumio sudo[9462]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:05 volumio volumio[9144]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:05 volumio volumio[9144]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:05 volumio volumio[9144]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 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. Feb 23 02:54:05 volumio sudo[9464]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:05 volumio volumio[9144]: info: Remote SSH Stopped Feb 23 02:54:05 volumio go-librespot[9425]: time="2026-02-23T02:54:05Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 23 02:54:05 volumio go-librespot[9425]: time="2026-02-23T02:54:05Z" level=debug msg="completed keyexchange" Feb 23 02:54:05 volumio go-librespot[9425]: time="2026-02-23T02:54:05Z" level=debug msg="completed challenge" Feb 23 02:54:05 volumio volumio[9144]: info: Setting Geolocation for MyVolumio to eu8 Feb 23 02:54:05 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:05 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:05 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:05 volumio go-librespot[9425]: time="2026-02-23T02:54:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:05 volumio volumio[9144]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 23 02:54:06 volumio go-librespot[9425]: time="2026-02-23T02:54:06Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 23 02:54:06 volumio go-librespot[9425]: time="2026-02-23T02:54:06Z" level=debug msg="completed keyexchange" Feb 23 02:54:06 volumio go-librespot[9425]: time="2026-02-23T02:54:06Z" level=debug msg="completed challenge" Feb 23 02:54:06 volumio go-librespot[9425]: time="2026-02-23T02:54:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:06 volumio volumio[9144]: info: Updating MyVolumio device info Feb 23 02:54:06 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:06 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:06 volumio volumio[9144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:06 volumio volumio[9144]: info: Getting Spotify volume Feb 23 02:54:06 volumio volumio[9144]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 23 02:54:06 volumio volumio[9144]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:06 volumio volumio[9144]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:06 volumio volumio[9144]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Feb 23 02:54:06 volumio volumio[9144]: SPOTIFY: SPOTIFY VOLUME undefined Feb 23 02:54:06 volumio volumio[9144]: SPOTIFY: VOLUMIO VOLUME 0 Feb 23 02:54:06 volumio volumio[9144]: info: Aligning Spotify Volume to Volumio Volume Feb 23 02:54:06 volumio volumio[9144]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:06 volumio volumio[9144]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:06 volumio volumio[9144]: info: Setting Spotify Volume from Volumio: 0 Feb 23 02:54:07 volumio volumio[9144]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 23 02:54:07 volumio go-librespot[9425]: time="2026-02-23T02:54:07Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 23 02:54:07 volumio go-librespot[9425]: time="2026-02-23T02:54:07Z" level=debug msg="completed keyexchange" Feb 23 02:54:07 volumio go-librespot[9425]: time="2026-02-23T02:54:07Z" level=debug msg="completed challenge" Feb 23 02:54:07 volumio go-librespot[9425]: time="2026-02-23T02:54:07Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:07 volumio go-librespot[9425]: time="2026-02-23T02:54:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:07 volumio volumio[9144]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:07 volumio volumio[9144]: Error: socket hang up Feb 23 02:54:07 volumio volumio[9144]: at connResetException (node:internal/errors:720:14) Feb 23 02:54:07 volumio volumio[9144]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 23 02:54:07 volumio volumio[9144]: at Socket.emit (node:events:526:35) Feb 23 02:54:07 volumio volumio[9144]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 23 02:54:07 volumio volumio[9144]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 23 02:54:07 volumio volumio[9144]: code: 'ECONNRESET', Feb 23 02:54:07 volumio volumio[9144]: response: undefined Feb 23 02:54:07 volumio volumio[9144]: } Feb 23 02:54:07 volumio volumio[9144]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:07 volumio sudo[9481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 02:53' Feb 23 02:54:07 volumio sudo[9481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:07 volumio sudo[9481]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:07 volumio volumio-remote-updater[945]: [2026-02-23 02:54:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 23 02:54:07 volumio volumio-remote-updater[945]: [2026-02-23 02:54:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 23 02:54:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 23 02:54:07 volumio systemd[1]: volumio.service: Consumed 8.964s CPU time. Feb 23 02:54:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8581. Feb 23 02:54:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:08 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 23 02:54:08 volumio systemd[1]: volumio.service: Consumed 8.964s CPU time. Feb 23 02:54:08 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 23 02:54:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:08 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:08 volumio volumio[9493]: info: ----- Volumio3 ---- Feb 23 02:54:08 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:08 volumio volumio[9493]: info: ----- System startup ---- Feb 23 02:54:08 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:08 volumio volumio[9493]: info: MYVOLUMIO Environment detected Feb 23 02:54:08 volumio volumio[9493]: info: Plugin folders cleanup Feb 23 02:54:08 volumio volumio[9493]: info: Scanning into folder /volumio/app/plugins/ Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category audio_interface Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category miscellanea Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category music_service Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category plugins.json Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category system_controller Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category user_interface Feb 23 02:54:08 volumio volumio[9493]: info: Scanning into folder /data/plugins/ Feb 23 02:54:08 volumio volumio[9493]: info: Scanning category music_service Feb 23 02:54:08 volumio volumio[9493]: info: Plugin folders cleanup completed Feb 23 02:54:08 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:08 volumio volumio[9493]: info: ----- Core plugins startup ---- Feb 23 02:54:08 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:08 volumio volumio[9493]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 02:54:08 volumio volumio[9493]: info: Adding plugin upnp to MyMusic Plugins Feb 23 02:54:08 volumio volumio[9493]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 02:54:08 volumio volumio[9493]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 02:54:08 volumio volumio[9493]: info: Loading plugins from folder /data/plugins/ Feb 23 02:54:08 volumio volumio[9493]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Feb 23 02:54:08 volumio volumio[9493]: info: Loading plugin "system"... Feb 23 02:54:08 volumio volumio[9493]: info: Loading plugin "appearance"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "network"... Feb 23 02:54:09 volumio volumio[9493]: info: Refreshing Cached IP Addresses Feb 23 02:54:09 volumio sudo[9521]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:09 volumio sudo[9521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:09 volumio sudo[9523]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:09 volumio sudo[9523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:09 volumio sudo[9521]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:09 volumio sudo[9523]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "services"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "alsa_controller"... Feb 23 02:54:09 volumio sudo[9532]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 02:54:09 volumio sudo[9532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:09 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "wizard"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "networkfs"... Feb 23 02:54:09 volumio volumio[9493]: info: Starting Udev Watcher for removable devices Feb 23 02:54:09 volumio volumio[9493]: info: Mounting Device 0ACB-A1DE Feb 23 02:54:09 volumio sudo[9560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Feb 23 02:54:09 volumio sudo[9560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:09 volumio sudo[9560]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:09 volumio volumio[9493]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:09 volumio volumio[9493]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:09 volumio volumio[9493]: 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 Feb 23 02:54:09 volumio volumio[9493]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:09 volumio volumio[9493]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:09 volumio volumio[9493]: info: Ignoring mount for partition: boot Feb 23 02:54:09 volumio volumio[9493]: info: Ignoring mount for partition: volumio Feb 23 02:54:09 volumio volumio[9493]: info: Ignoring mount for partition: volumio_data Feb 23 02:54:09 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "volumio_command_line_client"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "upnp"... Feb 23 02:54:09 volumio volumio[9493]: info: [1771815249368] Starting Upmpd Daemon Feb 23 02:54:09 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "my_music"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "mpd"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "upnp_browser"... Feb 23 02:54:09 volumio volumio[9493]: info: Starting UPNP Browser Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "alarm-clock"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "airplay_emulation"... Feb 23 02:54:09 volumio volumio[9493]: info: Starting Shairport Sync Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "last_100"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "webradio"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "i2s_dacs"... Feb 23 02:54:09 volumio volumio[9493]: info: Loading plugin "volumiodiscovery"... Feb 23 02:54:10 volumio volumio[9493]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:10 volumio volumio[9493]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:10 volumio volumio[9493]: *** WARNING *** For more information see Feb 23 02:54:10 volumio volumio[9493]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:10 volumio volumio[9493]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:10 volumio volumio[9493]: *** WARNING *** For more information see Feb 23 02:54:10 volumio node[9493]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:10 volumio node[9493]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:10 volumio node[9493]: *** WARNING *** For more information see Feb 23 02:54:10 volumio node[9493]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:10 volumio node[9493]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:10 volumio node[9493]: *** WARNING *** For more information see Feb 23 02:54:10 volumio volumio[9493]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 02:54:10 volumio volumio[9493]: info: Discovery: Started advertising with name: Volumio Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "spop"... Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "ytmusic"... Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "outputs"... Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "albumart"... Feb 23 02:54:10 volumio volumio[9493]: info: Plugin example_plugin is not enabled Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "inputs"... Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "updater_comm"... Feb 23 02:54:10 volumio volumio[9493]: info: Plugin mpdemulation is not enabled Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "rest_api"... Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "websocket"... Feb 23 02:54:10 volumio volumio[9493]: info: Starting Socket.io Server version 1.7.4 Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "podcast"... Feb 23 02:54:10 volumio volumio[9493]: info: ControllerPodcast::constructor Feb 23 02:54:10 volumio volumio[9493]: info: Loading plugin "rtlsdr_radio"... Feb 23 02:54:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 23 02:54:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:10 volumio volumio[9564]: Forking 3 albumart workers Feb 23 02:54:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:10 volumio go-librespot[9574]: go-librespot daemon starting... Feb 23 02:54:10 volumio go-librespot[9575]: time="2026-02-23T02:54:10Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:10 volumio go-librespot[9575]: time="2026-02-23T02:54:10Z" level=debug msg="app state loaded" Feb 23 02:54:10 volumio go-librespot[9575]: time="2026-02-23T02:54:10Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:10 volumio volumio[9493]: info: Loading i18n strings for locale en Feb 23 02:54:10 volumio volumio[9493]: Updating browse sources language Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::initPlayerControls Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: Express server listening on port 3000 Feb 23 02:54:10 volumio volumio[9493]: [Metrics] WebUI: 2s 305.41ms Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::resetVolumioState Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::getcurrentVolume Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:54:10 volumio volumio[9493]: info: Volumio Network Manager: Network status updated: 2 Feb 23 02:54:10 volumio volumio[9493]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::pushState Feb 23 02:54:10 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::updateTrackBlock Feb 23 02:54:10 volumio volumio[9493]: info: CorePlayQueue::getTrackBlock Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:10 volumio volumio[9493]: info: Reloading queue from file Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::setRepeat null single undefined Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::pushState Feb 23 02:54:10 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::setRandom true Feb 23 02:54:10 volumio volumio[9493]: info: CoreStateMachine::pushState Feb 23 02:54:10 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:10 volumio volumio[9493]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:10 volumio volumio[9493]: info: Setting Device type: Raspberry PI Feb 23 02:54:11 volumio volumio[9493]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 23 02:54:11 volumio volumio[9493]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Feb 23 02:54:11 volumio volumio[9493]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 23 02:54:11 volumio volumio[9493]: info: Completed loading Core Plugins Feb 23 02:54:11 volumio volumio[9493]: info: Preparing to generate the ALSA configuration file Feb 23 02:54:11 volumio volumio[9493]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:54:11 volumio volumio[9493]: info: CoreStateMachine::pushState Feb 23 02:54:11 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:11 volumio volumio[9493]: info: Asound.conf file unchanged, so no further update is needed Feb 23 02:54:11 volumio volumio[9493]: info: Output device has changed, restarting MPD Feb 23 02:54:11 volumio volumio[9493]: info: Output device has changed, restarting Shairport Sync Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:11 volumio sudo[9629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:54:11 volumio sudo[9629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio sudo[9631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:54:11 volumio sudo[9631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio sudo[9629]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio volumio[9493]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:11 volumio volumio[9493]: info: ___________ START PLUGINS ___________ Feb 23 02:54:11 volumio volumio[9493]: info: ControllerMpd::onStart: Initializing MPD Feb 23 02:54:11 volumio volumio[9493]: info: Creating MPD Configuration file Feb 23 02:54:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 02:54:11 volumio go-librespot[9575]: time="2026-02-23T02:54:11Z" 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]" Feb 23 02:54:11 volumio go-librespot[9575]: time="2026-02-23T02:54:11Z" 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]" Feb 23 02:54:11 volumio go-librespot[9575]: time="2026-02-23T02:54:11Z" 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]" Feb 23 02:54:11 volumio sudo[9639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:11 volumio volumio[9493]: info: [1771815251122] CoreMusicLibrary::Adding element Media Servers Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:11 volumio go-librespot[9575]: time="2026-02-23T02:54:11Z" level=info msg="zeroconf server listening on port 43679" Feb 23 02:54:11 volumio sudo[9639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:54:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:54:11 volumio sudo[9639]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:54:11 volumio volumio[9583]: Starting albumart workers Feb 23 02:54:11 volumio sudo[9641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:54:11 volumio volumio[9493]: info: UPNP Browser: Client initialized successfully Feb 23 02:54:11 volumio sudo[9641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:54:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:11 volumio volumio[9581]: Starting albumart workers Feb 23 02:54:11 volumio volumio[9493]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:54:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:54:11 volumio volumio[9493]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:54:11 volumio volumio[9493]: info: [1771815251197] CoreMusicLibrary::Adding element Last_100 Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:11 volumio volumio[9493]: info: [1771815251201] CoreMusicLibrary::Adding element Webradio Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:54:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:54:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:11 volumio volumio[9576]: Starting albumart workers Feb 23 02:54:11 volumio volumio[9493]: info: Initializing BBC Radios Feb 23 02:54:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:54:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: Creating Spotify config file Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio sudo[9662]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 02:54:11 volumio sudo[9662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 02:54:11 volumio sudo[9662]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:11 volumio volumio[9493]: info: [1771815251416] CoreMusicLibrary::Adding element YouTube Music Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:11 volumio volumio[9493]: Cannot find translation for source YouTube Music Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:11 volumio volumio[9493]: info: [1771815251420] CoreMusicLibrary::Adding element Podcast Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:11 volumio volumio[9493]: Cannot find translation for source YouTube Music Feb 23 02:54:11 volumio volumio[9493]: Cannot find translation for source Podcast Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Starting plugin Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Feb 23 02:54:11 volumio volumio[9493]: info: Volumio Calling Home Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] snd-aloop already loaded Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] No stations database found, creating v2 Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Database loaded at: 2026-02-23T02:54:11.481Z Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Got 21 phrases from file Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Updated metadata blocklist Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Management server started on port 3456 Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:11 volumio volumio[9493]: info: [1771815251524] CoreMusicLibrary::Adding element FM/DAB Radio Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:11 volumio volumio[9493]: Cannot find translation for source YouTube Music Feb 23 02:54:11 volumio volumio[9493]: Cannot find translation for source Podcast Feb 23 02:54:11 volumio volumio[9493]: Cannot find translation for source FM/DAB Radio Feb 23 02:54:11 volumio volumio[9493]: info: [RTL-SDR Radio] Plugin started successfully Feb 23 02:54:11 volumio volumio[9493]: info: MPD Permissions set Feb 23 02:54:11 volumio volumio[9493]: info: MPD Permissions set Feb 23 02:54:11 volumio volumio[9493]: info: Spotify config file written Feb 23 02:54:11 volumio sudo[9699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 02:54:11 volumio sudo[9699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio volumio[9493]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 02:54:11 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:11 volumio volumio[9493]: info: No need to fix Spotify hosts Feb 23 02:54:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:11 volumio go-librespot[9707]: go-librespot daemon starting... Feb 23 02:54:11 volumio sudo[9699]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio go-librespot[9712]: time="2026-02-23T02:54:11Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:11 volumio go-librespot[9712]: time="2026-02-23T02:54:11Z" level=debug msg="app state loaded" Feb 23 02:54:11 volumio go-librespot[9712]: time="2026-02-23T02:54:11Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:11 volumio volumio[9493]: info: Starting Shairport Sync Feb 23 02:54:11 volumio volumio[9493]: info: Starting Shairport Sync Feb 23 02:54:11 volumio volumio[9493]: info: Starting Shairport Sync Feb 23 02:54:11 volumio sudo[9719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:11 volumio sudo[9719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio sudo[9721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:11 volumio sudo[9721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio sudo[9724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:11 volumio sudo[9724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 02:54:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 02:54:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:54:11 volumio systemd[1]: shairport-sync.service: Consumed 1.543s CPU time. Feb 23 02:54:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:54:11 volumio sudo[9719]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio sudo[9724]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio sudo[9721]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:11 volumio volumio[9493]: info: Shairport-Sync Started Feb 23 02:54:11 volumio volumio[9493]: Error adding Membership: Error: addMembership EINVAL Feb 23 02:54:11 volumio volumio[9493]: info: Shairport-Sync Started Feb 23 02:54:11 volumio volumio[9493]: info: Shairport-Sync Started Feb 23 02:54:11 volumio volumio[9493]: info: Volumio called home Feb 23 02:54:11 volumio volumio[9493]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:54:11 volumio volumio[9493]: info: Discovery: Found device Volumio Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:11 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:11 volumio volumio[9493]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:54:11 volumio volumio[9493]: info: Discovery: Found device Volumio Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:11 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:11 volumio volumio[9493]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:11 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:12 volumio mpd[9672]: 2026-02-23T02:54:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 02:54:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 02:54:12 volumio sudo[9641]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:12 volumio sudo[9631]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:12 volumio volumio[9493]: info: Completed starting Core Plugins Feb 23 02:54:12 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:12 volumio volumio[9493]: info: ----- MyVolumio plugins startup ---- Feb 23 02:54:12 volumio volumio[9493]: info: ------------------------------------------- Feb 23 02:54:12 volumio volumio[9493]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 02:54:12 volumio volumio[9493]: error: MPD error: The expression evaluated to a falsy value: Feb 23 02:54:12 volumio volumio[9493]: assert.ok(self.idling) Feb 23 02:54:12 volumio volumio[9493]: error: The expression evaluated to a falsy value: Feb 23 02:54:12 volumio volumio[9493]: assert.ok(self.idling) Feb 23 02:54:12 volumio volumio[9493]: info: MPD running with PID9672 Feb 23 02:54:12 volumio volumio[9493]: ,establishing connection Feb 23 02:54:12 volumio volumio[9493]: error: updateQueue error: null Feb 23 02:54:12 volumio volumio[9493]: error: updateQueue error: null Feb 23 02:54:12 volumio go-librespot[9712]: time="2026-02-23T02:54:12Z" 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]" Feb 23 02:54:12 volumio go-librespot[9712]: time="2026-02-23T02:54:12Z" 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]" Feb 23 02:54:12 volumio go-librespot[9712]: time="2026-02-23T02:54:12Z" 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]" Feb 23 02:54:12 volumio volumio[9493]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 23 02:54:12 volumio go-librespot[9712]: time="2026-02-23T02:54:12Z" level=info msg="zeroconf server listening on port 34663" Feb 23 02:54:12 volumio go-librespot[9712]: time="2026-02-23T02:54:12Z" level=debug msg="obtained new client token: AAD3xeke5KQif35Amm0IVzoAE3GhzvwLAX6iw3IBdEsJVFli/xor3PUdfdwoyPu36PzteItMqPW2pUu4qku/OMwpBipfTBKSgBn5rTyx5HdwCjpAQIHEBvyvoIRPUvKwSemE1eCoMtkvhhRBl6hfo/YZob+qdIzkARskT6I1iuNjha8xBUUA3wZpBKDx6gXJK3K28oTwmcaPZ+vlSa/XYAG3M1aTVVGw6nNx4V08usoT6AtiJXSCByuuZQ==" Feb 23 02:54:12 volumio volumio-remote-updater[945]: [2026-02-23 02:54:12] [connect] Successful connection Feb 23 02:54:12 volumio volumio-remote-updater[945]: [2026-02-23 02:54:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771815252 101 Feb 23 02:54:12 volumio volumio[9493]: 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 Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" 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" Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:13 volumio sudo[9532]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=debug msg="completed keyexchange" Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=debug msg="completed challenge" Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=debug msg="completed keyexchange" Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=debug msg="completed challenge" Feb 23 02:54:13 volumio go-librespot[9712]: time="2026-02-23T02:54:13Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:14 volumio go-librespot[9712]: time="2026-02-23T02:54:14Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 23 02:54:14 volumio go-librespot[9712]: time="2026-02-23T02:54:14Z" level=debug msg="completed keyexchange" Feb 23 02:54:14 volumio go-librespot[9712]: time="2026-02-23T02:54:14Z" level=debug msg="completed challenge" Feb 23 02:54:14 volumio volumio[9493]: info: go-librespot daemon successfully initialized Feb 23 02:54:14 volumio go-librespot[9712]: time="2026-02-23T02:54:14Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:15 volumio go-librespot[9712]: time="2026-02-23T02:54:15Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 23 02:54:15 volumio go-librespot[9712]: time="2026-02-23T02:54:15Z" level=debug msg="completed keyexchange" Feb 23 02:54:15 volumio go-librespot[9712]: time="2026-02-23T02:54:15Z" level=debug msg="completed challenge" Feb 23 02:54:15 volumio go-librespot[9712]: time="2026-02-23T02:54:15Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:16 volumio go-librespot[9712]: time="2026-02-23T02:54:16Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 23 02:54:16 volumio go-librespot[9712]: time="2026-02-23T02:54:16Z" level=debug msg="completed keyexchange" Feb 23 02:54:16 volumio go-librespot[9712]: time="2026-02-23T02:54:16Z" level=debug msg="completed challenge" Feb 23 02:54:16 volumio go-librespot[9712]: time="2026-02-23T02:54:16Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:17 volumio go-librespot[9712]: time="2026-02-23T02:54:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:17 volumio go-librespot[9712]: time="2026-02-23T02:54:17Z" level=debug msg="completed keyexchange" Feb 23 02:54:17 volumio go-librespot[9712]: time="2026-02-23T02:54:17Z" level=debug msg="completed challenge" Feb 23 02:54:17 volumio go-librespot[9712]: time="2026-02-23T02:54:17Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:17 volumio go-librespot[9712]: time="2026-02-23T02:54:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:17 volumio volumio[9493]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:17 volumio volumio[9493]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 02:54:19 volumio sudo[9766]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:19 volumio sudo[9766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:19 volumio sudo[9768]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:19 volumio sudo[9768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:19 volumio sudo[9766]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:19 volumio sudo[9768]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:19 volumio sudo[9771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 02:54:19 volumio sudo[9771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:19 volumio sudo[9771]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:19 volumio volumio[9493]: info: Upmpdcli Daemon Started Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 02:54:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 23 02:54:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 02:54:20 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:20 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:20 volumio volumio[9493]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 02:54:20 volumio volumio[9493]: info: MyVolumio login type: Token Feb 23 02:54:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:20 volumio go-librespot[9774]: go-librespot daemon starting... Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" level=debug msg="app state loaded" Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" 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]" Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" 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]" Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" 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]" Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" level=info msg="zeroconf server listening on port 44551" Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 02:54:20 volumio volumio[9493]: info: Streaming services startup Feb 23 02:54:20 volumio volumio[9493]: info: Starting Streaming Daemon Feb 23 02:54:20 volumio sudo[9785]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:20 volumio sudo[9785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:20 volumio volumio[9493]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" level=debug msg="obtained new client token: AAAFX0p3jaJi+AR+y20g/ElLFltkXphNqDoXtIH5J3iDcwefG20CEaY4ZgwU38O05M/IPCLKbOw7wOJIJ2ZVrjOHUXXDh9aV/oqTfNNtSVUX0COc7IJH9yZ8s/Fim9162cf/R+I15BlVzKMhTMUEWhWwZu06ci8FLkpumDenqYsD2KIVINHcMaQJ1qvpONEfj6crR9Szlmwj400xx56PZ351f5UdPuQUd4N/gNucbAcltzFe9XNW6S/GOA==" Feb 23 02:54:20 volumio volumio[9493]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:20 volumio sudo[9785]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:20 volumio volumio[9493]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:20 volumio volumio[9493]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:20 volumio volumio[9493]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" level=debug msg="new websocket client" Feb 23 02:54:20 volumio volumio[9493]: info: Connection to go-librespot Websocket established Feb 23 02:54:20 volumio go-librespot[9775]: time="2026-02-23T02:54:20Z" 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" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=debug msg="completed keyexchange" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=debug msg="completed challenge" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:21 volumio volumio[9493]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=debug msg="completed keyexchange" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=debug msg="completed challenge" Feb 23 02:54:21 volumio go-librespot[9775]: time="2026-02-23T02:54:21Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:21 volumio volumio[9493]: info: MyVolumio token set successfully Feb 23 02:54:21 volumio volumio[9493]: info: MYVOLUMIO: Adding device Feb 23 02:54:21 volumio volumio[9493]: info: MYVOLUMIO: Evaluating Server Feb 23 02:54:21 volumio volumio[9493]: info: MyVolumio status changed Feb 23 02:54:21 volumio volumio[9493]: info: Streaming services startup Feb 23 02:54:21 volumio volumio[9493]: info: Starting Streaming Daemon Feb 23 02:54:21 volumio volumio[9493]: info: Removing browser output: myVolumio user plan is not superstar Feb 23 02:54:21 volumio volumio[9493]: info: Removing audio output: Feb 23 02:54:21 volumio volumio[9493]: info: Stoppping Tunnel 1 Feb 23 02:54:21 volumio sudo[9813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:21 volumio sudo[9813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:21 volumio sudo[9815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 23 02:54:21 volumio sudo[9815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:21 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. Feb 23 02:54:21 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. Feb 23 02:54:21 volumio sudo[9813]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:21 volumio volumio[9493]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:21 volumio volumio[9493]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:21 volumio volumio[9493]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:21 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. Feb 23 02:54:21 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. Feb 23 02:54:21 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. Feb 23 02:54:21 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. Feb 23 02:54:21 volumio sudo[9815]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:21 volumio volumio[9493]: info: Remote SSH Stopped Feb 23 02:54:22 volumio volumio[9493]: info: Setting Geolocation for MyVolumio to eu3 Feb 23 02:54:22 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:22 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:22 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:22 volumio go-librespot[9775]: time="2026-02-23T02:54:22Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 23 02:54:22 volumio go-librespot[9775]: time="2026-02-23T02:54:22Z" level=debug msg="completed keyexchange" Feb 23 02:54:22 volumio go-librespot[9775]: time="2026-02-23T02:54:22Z" level=debug msg="completed challenge" Feb 23 02:54:22 volumio volumio[9493]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 23 02:54:22 volumio go-librespot[9775]: time="2026-02-23T02:54:22Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 23 02:54:23 volumio volumio[9493]: info: Updating MyVolumio device info Feb 23 02:54:23 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:23 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:23 volumio volumio[9493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=debug msg="completed keyexchange" Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=debug msg="completed challenge" Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:23 volumio volumio[9493]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=debug msg="completed keyexchange" Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=debug msg="completed challenge" Feb 23 02:54:23 volumio volumio[9493]: info: Getting Spotify volume Feb 23 02:54:23 volumio go-librespot[9775]: time="2026-02-23T02:54:23Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:23 volumio volumio[9493]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 23 02:54:24 volumio volumio[9493]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:24 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:24 volumio volumio[9493]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Feb 23 02:54:24 volumio volumio[9493]: SPOTIFY: SPOTIFY VOLUME undefined Feb 23 02:54:24 volumio volumio[9493]: SPOTIFY: VOLUMIO VOLUME 0 Feb 23 02:54:24 volumio volumio[9493]: info: Aligning Spotify Volume to Volumio Volume Feb 23 02:54:24 volumio volumio[9493]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:24 volumio volumio[9493]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:24 volumio volumio[9493]: info: Setting Spotify Volume from Volumio: 0 Feb 23 02:54:24 volumio go-librespot[9775]: time="2026-02-23T02:54:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:24 volumio go-librespot[9775]: time="2026-02-23T02:54:24Z" level=debug msg="completed keyexchange" Feb 23 02:54:24 volumio go-librespot[9775]: time="2026-02-23T02:54:24Z" level=debug msg="completed challenge" Feb 23 02:54:24 volumio go-librespot[9775]: time="2026-02-23T02:54:24Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:24 volumio go-librespot[9775]: time="2026-02-23T02:54:24Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:24 volumio volumio[9493]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:24 volumio volumio[9493]: Error: socket hang up Feb 23 02:54:24 volumio volumio[9493]: at connResetException (node:internal/errors:720:14) Feb 23 02:54:24 volumio volumio[9493]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 23 02:54:24 volumio volumio[9493]: at Socket.emit (node:events:526:35) Feb 23 02:54:24 volumio volumio[9493]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 23 02:54:24 volumio volumio[9493]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 23 02:54:24 volumio volumio[9493]: code: 'ECONNRESET', Feb 23 02:54:24 volumio volumio[9493]: response: undefined Feb 23 02:54:24 volumio volumio[9493]: } Feb 23 02:54:24 volumio volumio[9493]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:24 volumio sudo[9832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 02:53' Feb 23 02:54:24 volumio sudo[9832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:24 volumio sudo[9832]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:24 volumio volumio-remote-updater[945]: [2026-02-23 02:54:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 23 02:54:24 volumio volumio-remote-updater[945]: [2026-02-23 02:54:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 23 02:54:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 23 02:54:24 volumio systemd[1]: volumio.service: Consumed 8.989s CPU time. Feb 23 02:54:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8582. Feb 23 02:54:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 23 02:54:25 volumio systemd[1]: volumio.service: Consumed 8.989s CPU time. Feb 23 02:54:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 23 02:54:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:25 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:25 volumio volumio[9844]: info: ----- Volumio3 ---- Feb 23 02:54:25 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:25 volumio volumio[9844]: info: ----- System startup ---- Feb 23 02:54:25 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:25 volumio volumio[9844]: info: MYVOLUMIO Environment detected Feb 23 02:54:25 volumio volumio[9844]: info: Plugin folders cleanup Feb 23 02:54:25 volumio volumio[9844]: info: Scanning into folder /volumio/app/plugins/ Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category audio_interface Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category miscellanea Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category music_service Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category plugins.json Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category system_controller Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category user_interface Feb 23 02:54:25 volumio volumio[9844]: info: Scanning into folder /data/plugins/ Feb 23 02:54:25 volumio volumio[9844]: info: Scanning category music_service Feb 23 02:54:25 volumio volumio[9844]: info: Plugin folders cleanup completed Feb 23 02:54:25 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:25 volumio volumio[9844]: info: ----- Core plugins startup ---- Feb 23 02:54:25 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:25 volumio volumio[9844]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 02:54:25 volumio volumio[9844]: info: Adding plugin upnp to MyMusic Plugins Feb 23 02:54:25 volumio volumio[9844]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 02:54:25 volumio volumio[9844]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 02:54:25 volumio volumio[9844]: info: Loading plugins from folder /data/plugins/ Feb 23 02:54:25 volumio volumio[9844]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Feb 23 02:54:25 volumio volumio[9844]: info: Loading plugin "system"... Feb 23 02:54:25 volumio volumio[9844]: info: Loading plugin "appearance"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "network"... Feb 23 02:54:26 volumio volumio[9844]: info: Refreshing Cached IP Addresses Feb 23 02:54:26 volumio sudo[9872]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:26 volumio sudo[9872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:26 volumio sudo[9874]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:26 volumio sudo[9874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:26 volumio sudo[9872]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:26 volumio sudo[9874]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "services"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "alsa_controller"... Feb 23 02:54:26 volumio sudo[9886]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 02:54:26 volumio sudo[9886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:26 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "wizard"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "networkfs"... Feb 23 02:54:26 volumio volumio[9844]: info: Starting Udev Watcher for removable devices Feb 23 02:54:26 volumio volumio[9844]: info: Mounting Device 0ACB-A1DE Feb 23 02:54:26 volumio sudo[9911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Feb 23 02:54:26 volumio sudo[9911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:26 volumio sudo[9911]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:26 volumio volumio[9844]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:26 volumio volumio[9844]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:26 volumio volumio[9844]: 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 Feb 23 02:54:26 volumio volumio[9844]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:26 volumio volumio[9844]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:26 volumio volumio[9844]: info: Ignoring mount for partition: boot Feb 23 02:54:26 volumio volumio[9844]: info: Ignoring mount for partition: volumio Feb 23 02:54:26 volumio volumio[9844]: info: Ignoring mount for partition: volumio_data Feb 23 02:54:26 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "volumio_command_line_client"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "upnp"... Feb 23 02:54:26 volumio volumio[9844]: info: [1771815266373] Starting Upmpd Daemon Feb 23 02:54:26 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "my_music"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "mpd"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "upnp_browser"... Feb 23 02:54:26 volumio volumio[9844]: info: Starting UPNP Browser Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "alarm-clock"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "airplay_emulation"... Feb 23 02:54:26 volumio volumio[9844]: info: Starting Shairport Sync Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "last_100"... Feb 23 02:54:26 volumio volumio[9844]: info: Loading plugin "webradio"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "i2s_dacs"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "volumiodiscovery"... Feb 23 02:54:27 volumio volumio[9844]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:27 volumio volumio[9844]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:27 volumio volumio[9844]: *** WARNING *** For more information see Feb 23 02:54:27 volumio volumio[9844]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:27 volumio volumio[9844]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:27 volumio node[9844]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:27 volumio volumio[9844]: *** WARNING *** For more information see Feb 23 02:54:27 volumio node[9844]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:27 volumio node[9844]: *** WARNING *** For more information see Feb 23 02:54:27 volumio node[9844]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:27 volumio node[9844]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:27 volumio node[9844]: *** WARNING *** For more information see Feb 23 02:54:27 volumio volumio[9844]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 02:54:27 volumio volumio[9844]: info: Discovery: Started advertising with name: Volumio Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "spop"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "ytmusic"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "outputs"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "albumart"... Feb 23 02:54:27 volumio volumio[9844]: info: Plugin example_plugin is not enabled Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "inputs"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "updater_comm"... Feb 23 02:54:27 volumio volumio[9844]: info: Plugin mpdemulation is not enabled Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "rest_api"... Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "websocket"... Feb 23 02:54:27 volumio volumio[9844]: info: Starting Socket.io Server version 1.7.4 Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "podcast"... Feb 23 02:54:27 volumio volumio[9844]: info: ControllerPodcast::constructor Feb 23 02:54:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 23 02:54:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:27 volumio volumio[9844]: info: Loading plugin "rtlsdr_radio"... Feb 23 02:54:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:27 volumio go-librespot[9925]: go-librespot daemon starting... Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" level=debug msg="app state loaded" Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:27 volumio volumio[9915]: Forking 3 albumart workers Feb 23 02:54:27 volumio volumio[9844]: info: Loading i18n strings for locale en Feb 23 02:54:27 volumio volumio[9844]: Updating browse sources language Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" 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]" Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" 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]" Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" 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]" Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::initPlayerControls Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio go-librespot[9926]: time="2026-02-23T02:54:27Z" level=info msg="zeroconf server listening on port 41533" Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:27 volumio volumio[9844]: Express server listening on port 3000 Feb 23 02:54:27 volumio volumio[9844]: [Metrics] WebUI: 2s 359.26ms Feb 23 02:54:27 volumio volumio[9844]: info: CoreStateMachine::resetVolumioState Feb 23 02:54:27 volumio volumio[9844]: info: CoreStateMachine::getcurrentVolume Feb 23 02:54:27 volumio volumio[9844]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:54:27 volumio volumio[9844]: info: Volumio Network Manager: Network status updated: 2 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: Reloading queue from file Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::setRepeat null single undefined Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::pushState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::setRandom true Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::pushState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:28 volumio volumio[9844]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::pushState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::updateTrackBlock Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrackBlock Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:54:28 volumio volumio[9844]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 23 02:54:28 volumio volumio[9844]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Feb 23 02:54:28 volumio volumio[9844]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 23 02:54:28 volumio volumio[9844]: info: Setting Device type: Raspberry PI Feb 23 02:54:28 volumio volumio[9844]: info: Completed loading Core Plugins Feb 23 02:54:28 volumio volumio[9844]: info: Preparing to generate the ALSA configuration file Feb 23 02:54:28 volumio volumio[9933]: Starting albumart workers Feb 23 02:54:28 volumio volumio[9932]: Starting albumart workers Feb 23 02:54:28 volumio volumio[9844]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:54:28 volumio volumio[9844]: info: CoreStateMachine::pushState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:28 volumio volumio[9844]: info: Asound.conf file unchanged, so no further update is needed Feb 23 02:54:28 volumio volumio[9844]: info: Output device has changed, restarting MPD Feb 23 02:54:28 volumio volumio[9844]: info: Output device has changed, restarting Shairport Sync Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio volumio[9934]: Starting albumart workers Feb 23 02:54:28 volumio sudo[9982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:54:28 volumio sudo[9982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio volumio[9844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:28 volumio volumio[9844]: info: ___________ START PLUGINS ___________ Feb 23 02:54:28 volumio sudo[9982]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio volumio[9844]: info: ControllerMpd::onStart: Initializing MPD Feb 23 02:54:28 volumio volumio[9844]: info: Creating MPD Configuration file Feb 23 02:54:28 volumio sudo[9986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:54:28 volumio sudo[9986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:28 volumio volumio[9844]: info: [1771815268204] CoreMusicLibrary::Adding element Media Servers Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:28 volumio sudo[9991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:54:28 volumio sudo[9991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio volumio[9844]: info: UPNP Browser: Client initialized successfully Feb 23 02:54:28 volumio sudo[9991]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 02:54:28 volumio sudo[9994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:54:28 volumio sudo[9994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:54:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:54:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:54:28 volumio go-librespot[9926]: time="2026-02-23T02:54:28Z" level=debug msg="obtained new client token: AAC7txO4kVaEubGVkBWUTFFpkCGIHM+hLYzWGvE9cZZFE55ApMuOwvG+X3hImi1jnDQNUwTsn7QyeCvs1ORh+aPCATGl0T5FMRWhPKA8SKkzBlAIOfns5uhhIDqWyG/2bD+oN224zAeQg0nLO9KXiHm0CMt3441xmTNUq/QV3vIAE0Lf37oRV033cPDZOpNZynwIgAcxAnkPryOa3vsHonvVkRwW9NfE/muFWSGM+hm7pP3HZwYtuV4=" Feb 23 02:54:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:54:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:54:28 volumio volumio[9844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:54:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:54:28 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:54:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:54:28 volumio volumio[9844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:28 volumio volumio[9844]: info: [1771815268310] CoreMusicLibrary::Adding element Last_100 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:54:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:28 volumio volumio[9844]: info: [1771815268314] CoreMusicLibrary::Adding element Webradio Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:54:28 volumio volumio[9844]: info: Initializing BBC Radios Feb 23 02:54:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: Creating Spotify config file Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio sudo[10008]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 02:54:28 volumio sudo[10008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 02:54:28 volumio sudo[10008]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:28 volumio volumio[9844]: info: [1771815268509] CoreMusicLibrary::Adding element YouTube Music Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:28 volumio volumio[9844]: Cannot find translation for source YouTube Music Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:28 volumio volumio[9844]: info: [1771815268513] CoreMusicLibrary::Adding element Podcast Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:28 volumio volumio[9844]: Cannot find translation for source YouTube Music Feb 23 02:54:28 volumio volumio[9844]: Cannot find translation for source Podcast Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Starting plugin Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Feb 23 02:54:28 volumio volumio[9844]: info: Volumio Calling Home Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] snd-aloop already loaded Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] No stations database found, creating v2 Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Database loaded at: 2026-02-23T02:54:28.556Z Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Got 21 phrases from file Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Updated metadata blocklist Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Management server started on port 3456 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:28 volumio volumio[9844]: info: [1771815268589] CoreMusicLibrary::Adding element FM/DAB Radio Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:28 volumio volumio[9844]: Cannot find translation for source YouTube Music Feb 23 02:54:28 volumio volumio[9844]: Cannot find translation for source Podcast Feb 23 02:54:28 volumio volumio[9844]: Cannot find translation for source FM/DAB Radio Feb 23 02:54:28 volumio volumio[9844]: info: [RTL-SDR Radio] Plugin started successfully Feb 23 02:54:28 volumio go-librespot[9926]: time="2026-02-23T02:54:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:28 volumio volumio[9844]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:54:28 volumio volumio[9844]: info: Discovery: Found device Volumio Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio volumio[9844]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:54:28 volumio volumio[9844]: info: Discovery: Found device Volumio Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio volumio[9844]: info: MPD Permissions set Feb 23 02:54:28 volumio volumio[9844]: info: MPD Permissions set Feb 23 02:54:28 volumio volumio[9844]: info: Spotify config file written Feb 23 02:54:28 volumio sudo[10051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 02:54:28 volumio sudo[10051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio go-librespot[9926]: time="2026-02-23T02:54:28Z" level=debug msg="completed keyexchange" Feb 23 02:54:28 volumio go-librespot[9926]: time="2026-02-23T02:54:28Z" level=debug msg="completed challenge" Feb 23 02:54:28 volumio volumio[9844]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 02:54:28 volumio systemd[1]: go-librespot-daemon.service: Killing process 9963 (go-librespot) with signal SIGKILL. Feb 23 02:54:28 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 02:54:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:28 volumio volumio[9844]: info: No need to fix Spotify hosts Feb 23 02:54:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:28 volumio go-librespot[10058]: go-librespot daemon starting... Feb 23 02:54:28 volumio sudo[10051]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio volumio[9844]: info: Starting Shairport Sync Feb 23 02:54:28 volumio go-librespot[10064]: time="2026-02-23T02:54:28Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:28 volumio go-librespot[10064]: time="2026-02-23T02:54:28Z" level=debug msg="app state loaded" Feb 23 02:54:28 volumio go-librespot[10064]: time="2026-02-23T02:54:28Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:28 volumio volumio[9844]: info: Starting Shairport Sync Feb 23 02:54:28 volumio volumio[9844]: info: Starting Shairport Sync Feb 23 02:54:28 volumio sudo[10071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:28 volumio sudo[10071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio sudo[10073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:28 volumio sudo[10073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio sudo[10075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:28 volumio sudo[10075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:28 volumio volumio[9844]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:28 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 02:54:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 02:54:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:54:28 volumio systemd[1]: shairport-sync.service: Consumed 1.552s CPU time. Feb 23 02:54:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:54:28 volumio sudo[10075]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio sudo[10071]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio sudo[10073]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:28 volumio volumio[9844]: info: Volumio called home Feb 23 02:54:28 volumio volumio[9844]: info: Shairport-Sync Started Feb 23 02:54:28 volumio volumio[9844]: Error adding Membership: Error: addMembership EINVAL Feb 23 02:54:28 volumio volumio[9844]: info: Shairport-Sync Started Feb 23 02:54:28 volumio volumio[9844]: info: Shairport-Sync Started Feb 23 02:54:28 volumio volumio[9844]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 23 02:54:29 volumio mpd[10035]: 2026-02-23T02:54:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 02:54:29 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 02:54:29 volumio sudo[9994]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:29 volumio sudo[9986]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:29 volumio volumio[9844]: info: Completed starting Core Plugins Feb 23 02:54:29 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:29 volumio volumio[9844]: info: ----- MyVolumio plugins startup ---- Feb 23 02:54:29 volumio volumio[9844]: info: ------------------------------------------- Feb 23 02:54:29 volumio volumio[9844]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 02:54:29 volumio go-librespot[10064]: time="2026-02-23T02:54:29Z" 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]" Feb 23 02:54:29 volumio go-librespot[10064]: time="2026-02-23T02:54:29Z" 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]" Feb 23 02:54:29 volumio go-librespot[10064]: time="2026-02-23T02:54:29Z" 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]" Feb 23 02:54:29 volumio go-librespot[10064]: time="2026-02-23T02:54:29Z" level=info msg="zeroconf server listening on port 35349" Feb 23 02:54:29 volumio volumio[9844]: error: MPD error: The expression evaluated to a falsy value: Feb 23 02:54:29 volumio volumio[9844]: assert.ok(self.idling) Feb 23 02:54:29 volumio volumio[9844]: error: The expression evaluated to a falsy value: Feb 23 02:54:29 volumio volumio[9844]: assert.ok(self.idling) Feb 23 02:54:29 volumio volumio[9844]: info: MPD running with PID10035 Feb 23 02:54:29 volumio volumio[9844]: ,establishing connection Feb 23 02:54:29 volumio volumio[9844]: error: updateQueue error: null Feb 23 02:54:29 volumio volumio[9844]: error: updateQueue error: null Feb 23 02:54:29 volumio go-librespot[10064]: time="2026-02-23T02:54:29Z" level=debug msg="obtained new client token: AAD+1VJmTowPvUHAEycnuyIWAfRPo702Tl8NKxnFeqcIKHdCE3J1kngT7jmsmDCFxvMQmPjiFCdFMHdqS0Z74YNrjByob+GYetMc++uUA5qdnbxWA1550Fmpporsavnz81lfWolPx4BSvBuLAi6De+rehqi2wsgYbATXKpB6B1Vk9qfKfY6ahEFjVZqe0ddAJJKswbwTDrqqkfx4yMS/V9HQM8m4fydRJRIFG08hWiQBXcPyb6JK/dvAwA==" Feb 23 02:54:29 volumio volumio-remote-updater[945]: [2026-02-23 02:54:29] [connect] Successful connection Feb 23 02:54:29 volumio volumio[9844]: 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 Feb 23 02:54:29 volumio volumio-remote-updater[945]: [2026-02-23 02:54:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771815269 101 Feb 23 02:54:29 volumio go-librespot[10064]: time="2026-02-23T02:54:29Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=debug msg="completed keyexchange" Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=debug msg="completed challenge" Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:30 volumio sudo[9886]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=debug msg="completed keyexchange" Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=debug msg="completed challenge" Feb 23 02:54:30 volumio go-librespot[10064]: time="2026-02-23T02:54:30Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=debug msg="completed keyexchange" Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=debug msg="completed challenge" Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:31 volumio volumio[9844]: info: go-librespot daemon successfully initialized Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=debug msg="completed keyexchange" Feb 23 02:54:31 volumio go-librespot[10064]: time="2026-02-23T02:54:31Z" level=debug msg="completed challenge" Feb 23 02:54:32 volumio go-librespot[10064]: time="2026-02-23T02:54:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:32 volumio go-librespot[10064]: time="2026-02-23T02:54:32Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 23 02:54:32 volumio go-librespot[10064]: time="2026-02-23T02:54:32Z" level=debug msg="completed keyexchange" Feb 23 02:54:32 volumio go-librespot[10064]: time="2026-02-23T02:54:32Z" level=debug msg="completed challenge" Feb 23 02:54:32 volumio go-librespot[10064]: time="2026-02-23T02:54:32Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:33 volumio go-librespot[10064]: time="2026-02-23T02:54:33Z" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 23 02:54:33 volumio go-librespot[10064]: time="2026-02-23T02:54:33Z" level=debug msg="completed keyexchange" Feb 23 02:54:33 volumio go-librespot[10064]: time="2026-02-23T02:54:33Z" level=debug msg="completed challenge" Feb 23 02:54:33 volumio go-librespot[10064]: time="2026-02-23T02:54:33Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:33 volumio go-librespot[10064]: time="2026-02-23T02:54:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:34 volumio volumio[9844]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:34 volumio volumio[9844]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 02:54:36 volumio sudo[10118]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:36 volumio sudo[10118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:36 volumio sudo[10120]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:36 volumio sudo[10120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:36 volumio sudo[10118]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:36 volumio sudo[10120]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:36 volumio sudo[10123]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 02:54:36 volumio sudo[10123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:36 volumio sudo[10123]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:36 volumio volumio[9844]: info: Upmpdcli Daemon Started Feb 23 02:54:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 23 02:54:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:36 volumio go-librespot[10126]: go-librespot daemon starting... Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" level=debug msg="app state loaded" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" 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]" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" 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]" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" 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]" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" level=info msg="zeroconf server listening on port 43703" Feb 23 02:54:36 volumio go-librespot[10127]: time="2026-02-23T02:54:36Z" level=debug msg="obtained new client token: AAD85F/yQS5VxAVJ7VPR/QlTscDyfA8nyc5utebLVq+IVOjzhHufm3vBgC4iDkBiQIHqzOcB9+tjGUGWwLoq6tFFK6NmuahPKdx65Ts44/SvXrLdT/8gkvVknt2Clj6cwjoAzc7t7uYh7o+NDzRvbw+ayvwvA8o7NLPZYt18s8CvjXnaOl2/I8Yxy9JrqQxfR286mzT/wTcC60tezXZZUQhgbeRbfXLOrs3xU3+uCcPoXdE0Bh+s1LNUMA==" Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" 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" Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=debug msg="completed keyexchange" Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=debug msg="completed challenge" Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 02:54:37 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:37 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:37 volumio volumio[9844]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 02:54:37 volumio volumio[9844]: info: MyVolumio login type: Token Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=debug msg="completed keyexchange" Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=debug msg="completed challenge" Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 02:54:37 volumio go-librespot[10127]: time="2026-02-23T02:54:37Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 02:54:37 volumio volumio[9844]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 02:54:37 volumio volumio[9844]: info: Streaming services startup Feb 23 02:54:37 volumio volumio[9844]: info: Starting Streaming Daemon Feb 23 02:54:38 volumio sudo[10137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:38 volumio sudo[10137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:38 volumio volumio[9844]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 02:54:38 volumio sudo[10137]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:38 volumio volumio[9844]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:38 volumio volumio[9844]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:38 volumio volumio[9844]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:38 volumio volumio[9844]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:38 volumio go-librespot[10127]: time="2026-02-23T02:54:38Z" level=debug msg="new websocket client" Feb 23 02:54:38 volumio volumio[9844]: info: Connection to go-librespot Websocket established Feb 23 02:54:38 volumio go-librespot[10127]: time="2026-02-23T02:54:38Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 23 02:54:38 volumio volumio[9844]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 23 02:54:38 volumio go-librespot[10127]: time="2026-02-23T02:54:38Z" level=debug msg="completed keyexchange" Feb 23 02:54:38 volumio go-librespot[10127]: time="2026-02-23T02:54:38Z" level=debug msg="completed challenge" Feb 23 02:54:38 volumio go-librespot[10127]: time="2026-02-23T02:54:38Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:38 volumio volumio[9844]: info: MyVolumio token set successfully Feb 23 02:54:38 volumio volumio[9844]: info: MYVOLUMIO: Adding device Feb 23 02:54:38 volumio volumio[9844]: info: MYVOLUMIO: Evaluating Server Feb 23 02:54:39 volumio go-librespot[10127]: time="2026-02-23T02:54:39Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 23 02:54:39 volumio go-librespot[10127]: time="2026-02-23T02:54:39Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 23 02:54:39 volumio volumio[9844]: info: MyVolumio status changed Feb 23 02:54:39 volumio volumio[9844]: info: Streaming services startup Feb 23 02:54:39 volumio volumio[9844]: info: Starting Streaming Daemon Feb 23 02:54:39 volumio volumio[9844]: info: Removing browser output: myVolumio user plan is not superstar Feb 23 02:54:39 volumio volumio[9844]: info: Removing audio output: Feb 23 02:54:39 volumio volumio[9844]: info: Stoppping Tunnel 1 Feb 23 02:54:39 volumio sudo[10147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:39 volumio sudo[10147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:39 volumio sudo[10149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 23 02:54:39 volumio sudo[10149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:39 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. Feb 23 02:54:39 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. Feb 23 02:54:39 volumio sudo[10147]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:39 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. Feb 23 02:54:39 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. Feb 23 02:54:39 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. Feb 23 02:54:39 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. Feb 23 02:54:39 volumio sudo[10149]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:39 volumio volumio[9844]: info: Remote SSH Stopped Feb 23 02:54:39 volumio volumio[9844]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:39 volumio volumio[9844]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:39 volumio volumio[9844]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:39 volumio go-librespot[10127]: time="2026-02-23T02:54:39Z" level=debug msg="completed keyexchange" Feb 23 02:54:39 volumio go-librespot[10127]: time="2026-02-23T02:54:39Z" level=debug msg="completed challenge" Feb 23 02:54:39 volumio volumio[9844]: info: Setting Geolocation for MyVolumio to eu12 Feb 23 02:54:39 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:39 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:39 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:39 volumio go-librespot[10127]: time="2026-02-23T02:54:39Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:40 volumio volumio[9844]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 23 02:54:40 volumio go-librespot[10127]: time="2026-02-23T02:54:40Z" 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" Feb 23 02:54:40 volumio go-librespot[10127]: time="2026-02-23T02:54:40Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:40 volumio go-librespot[10127]: time="2026-02-23T02:54:40Z" level=debug msg="completed keyexchange" Feb 23 02:54:40 volumio go-librespot[10127]: time="2026-02-23T02:54:40Z" level=debug msg="completed challenge" Feb 23 02:54:40 volumio go-librespot[10127]: time="2026-02-23T02:54:40Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:40 volumio volumio[9844]: info: Updating MyVolumio device info Feb 23 02:54:40 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:40 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:40 volumio volumio[9844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:41 volumio volumio[9844]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 23 02:54:41 volumio go-librespot[10127]: time="2026-02-23T02:54:41Z" 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" Feb 23 02:54:41 volumio volumio[9844]: info: Getting Spotify volume Feb 23 02:54:41 volumio volumio[9844]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 23 02:54:41 volumio volumio[9844]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:41 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:41 volumio volumio[9844]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Feb 23 02:54:41 volumio volumio[9844]: SPOTIFY: SPOTIFY VOLUME undefined Feb 23 02:54:41 volumio volumio[9844]: SPOTIFY: VOLUMIO VOLUME 0 Feb 23 02:54:41 volumio volumio[9844]: info: Aligning Spotify Volume to Volumio Volume Feb 23 02:54:41 volumio volumio[9844]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:41 volumio volumio[9844]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:41 volumio volumio[9844]: info: Setting Spotify Volume from Volumio: 0 Feb 23 02:54:41 volumio go-librespot[10127]: time="2026-02-23T02:54:41Z" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 23 02:54:41 volumio go-librespot[10127]: time="2026-02-23T02:54:41Z" level=debug msg="completed keyexchange" Feb 23 02:54:41 volumio go-librespot[10127]: time="2026-02-23T02:54:41Z" level=debug msg="completed challenge" Feb 23 02:54:41 volumio go-librespot[10127]: time="2026-02-23T02:54:41Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:41 volumio go-librespot[10127]: time="2026-02-23T02:54:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:41 volumio volumio[9844]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:41 volumio volumio[9844]: Error: socket hang up Feb 23 02:54:41 volumio volumio[9844]: at connResetException (node:internal/errors:720:14) Feb 23 02:54:41 volumio volumio[9844]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 23 02:54:41 volumio volumio[9844]: at Socket.emit (node:events:526:35) Feb 23 02:54:41 volumio volumio[9844]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 23 02:54:41 volumio volumio[9844]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 23 02:54:41 volumio volumio[9844]: code: 'ECONNRESET', Feb 23 02:54:41 volumio volumio[9844]: response: undefined Feb 23 02:54:41 volumio volumio[9844]: } Feb 23 02:54:41 volumio volumio[9844]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:41 volumio sudo[10184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 02:53' Feb 23 02:54:41 volumio sudo[10184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:41 volumio sudo[10184]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:41 volumio volumio-remote-updater[945]: [2026-02-23 02:54:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 23 02:54:41 volumio volumio-remote-updater[945]: [2026-02-23 02:54:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 23 02:54:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 23 02:54:41 volumio systemd[1]: volumio.service: Consumed 9.079s CPU time. Feb 23 02:54:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8583. Feb 23 02:54:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:41 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 23 02:54:41 volumio systemd[1]: volumio.service: Consumed 9.079s CPU time. Feb 23 02:54:41 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 23 02:54:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:42 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:42 volumio volumio[10196]: info: ----- Volumio3 ---- Feb 23 02:54:42 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:42 volumio volumio[10196]: info: ----- System startup ---- Feb 23 02:54:42 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:42 volumio volumio[10196]: info: MYVOLUMIO Environment detected Feb 23 02:54:42 volumio volumio[10196]: info: Plugin folders cleanup Feb 23 02:54:42 volumio volumio[10196]: info: Scanning into folder /volumio/app/plugins/ Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category audio_interface Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category miscellanea Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category music_service Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category plugins.json Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category system_controller Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category user_interface Feb 23 02:54:42 volumio volumio[10196]: info: Scanning into folder /data/plugins/ Feb 23 02:54:42 volumio volumio[10196]: info: Scanning category music_service Feb 23 02:54:42 volumio volumio[10196]: info: Plugin folders cleanup completed Feb 23 02:54:42 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:42 volumio volumio[10196]: info: ----- Core plugins startup ---- Feb 23 02:54:42 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:42 volumio volumio[10196]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 02:54:42 volumio volumio[10196]: info: Adding plugin upnp to MyMusic Plugins Feb 23 02:54:42 volumio volumio[10196]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 02:54:42 volumio volumio[10196]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 02:54:42 volumio volumio[10196]: info: Loading plugins from folder /data/plugins/ Feb 23 02:54:42 volumio volumio[10196]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Feb 23 02:54:42 volumio volumio[10196]: info: Loading plugin "system"... Feb 23 02:54:42 volumio volumio[10196]: info: Loading plugin "appearance"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "network"... Feb 23 02:54:43 volumio volumio[10196]: info: Refreshing Cached IP Addresses Feb 23 02:54:43 volumio sudo[10224]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:43 volumio sudo[10224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:43 volumio sudo[10224]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:43 volumio sudo[10226]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:43 volumio sudo[10226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "services"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "alsa_controller"... Feb 23 02:54:43 volumio sudo[10226]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:43 volumio sudo[10235]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 02:54:43 volumio sudo[10235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:43 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "wizard"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "networkfs"... Feb 23 02:54:43 volumio volumio[10196]: info: Starting Udev Watcher for removable devices Feb 23 02:54:43 volumio volumio[10196]: info: Mounting Device 0ACB-A1DE Feb 23 02:54:43 volumio sudo[10263]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Feb 23 02:54:43 volumio sudo[10263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:43 volumio sudo[10263]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:43 volumio volumio[10196]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:43 volumio volumio[10196]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:43 volumio volumio[10196]: 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 Feb 23 02:54:43 volumio volumio[10196]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:43 volumio volumio[10196]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:43 volumio volumio[10196]: info: Ignoring mount for partition: boot Feb 23 02:54:43 volumio volumio[10196]: info: Ignoring mount for partition: volumio Feb 23 02:54:43 volumio volumio[10196]: info: Ignoring mount for partition: volumio_data Feb 23 02:54:43 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "volumio_command_line_client"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "upnp"... Feb 23 02:54:43 volumio volumio[10196]: info: [1771815283116] Starting Upmpd Daemon Feb 23 02:54:43 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "my_music"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "mpd"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "upnp_browser"... Feb 23 02:54:43 volumio volumio[10196]: info: Starting UPNP Browser Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "alarm-clock"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "airplay_emulation"... Feb 23 02:54:43 volumio volumio[10196]: info: Starting Shairport Sync Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "last_100"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "webradio"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "i2s_dacs"... Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "volumiodiscovery"... Feb 23 02:54:43 volumio volumio[10196]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:43 volumio volumio[10196]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:43 volumio volumio[10196]: *** WARNING *** For more information see Feb 23 02:54:43 volumio volumio[10196]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:43 volumio volumio[10196]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:43 volumio volumio[10196]: *** WARNING *** For more information see Feb 23 02:54:43 volumio node[10196]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:43 volumio node[10196]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:43 volumio node[10196]: *** WARNING *** For more information see Feb 23 02:54:43 volumio node[10196]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:54:43 volumio node[10196]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:54:43 volumio node[10196]: *** WARNING *** For more information see Feb 23 02:54:43 volumio volumio[10196]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 02:54:43 volumio volumio[10196]: info: Discovery: Started advertising with name: Volumio Feb 23 02:54:43 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:43 volumio volumio[10196]: info: Loading plugin "spop"... Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "ytmusic"... Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "outputs"... Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "albumart"... Feb 23 02:54:44 volumio volumio[10196]: info: Plugin example_plugin is not enabled Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "inputs"... Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "updater_comm"... Feb 23 02:54:44 volumio volumio[10196]: info: Plugin mpdemulation is not enabled Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "rest_api"... Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "websocket"... Feb 23 02:54:44 volumio volumio[10196]: info: Starting Socket.io Server version 1.7.4 Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "podcast"... Feb 23 02:54:44 volumio volumio[10196]: info: ControllerPodcast::constructor Feb 23 02:54:44 volumio volumio[10196]: info: Loading plugin "rtlsdr_radio"... Feb 23 02:54:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 23 02:54:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:44 volumio volumio[10267]: Forking 3 albumart workers Feb 23 02:54:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:44 volumio go-librespot[10277]: go-librespot daemon starting... Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" level=debug msg="app state loaded" Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:44 volumio volumio[10196]: info: Loading i18n strings for locale en Feb 23 02:54:44 volumio volumio[10196]: Updating browse sources language Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::initPlayerControls Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: Express server listening on port 3000 Feb 23 02:54:44 volumio volumio[10196]: [Metrics] WebUI: 2s 298.89ms Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::resetVolumioState Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::getcurrentVolume Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:54:44 volumio volumio[10196]: info: Volumio Network Manager: Network status updated: 2 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: Reloading queue from file Feb 23 02:54:44 volumio volumio[10196]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::pushState Feb 23 02:54:44 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::updateTrackBlock Feb 23 02:54:44 volumio volumio[10196]: info: CorePlayQueue::getTrackBlock Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::setRepeat null single undefined Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::pushState Feb 23 02:54:44 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::setRandom true Feb 23 02:54:44 volumio volumio[10196]: info: CoreStateMachine::pushState Feb 23 02:54:44 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:44 volumio volumio[10196]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 23 02:54:44 volumio volumio[10196]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Feb 23 02:54:44 volumio volumio[10196]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 23 02:54:44 volumio volumio[10196]: info: Setting Device type: Raspberry PI Feb 23 02:54:44 volumio volumio[10196]: info: Completed loading Core Plugins Feb 23 02:54:44 volumio volumio[10196]: info: Preparing to generate the ALSA configuration file Feb 23 02:54:44 volumio volumio[10196]: info: Asound.conf file unchanged, so no further update is needed Feb 23 02:54:44 volumio volumio[10196]: info: Output device has changed, restarting MPD Feb 23 02:54:44 volumio volumio[10196]: info: Output device has changed, restarting Shairport Sync Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:44 volumio volumio[10280]: Starting albumart workers Feb 23 02:54:44 volumio sudo[10331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:54:44 volumio sudo[10331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:44 volumio sudo[10331]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:44 volumio sudo[10333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:54:44 volumio sudo[10333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:44 volumio volumio[10196]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:44 volumio volumio[10196]: info: ___________ START PLUGINS ___________ Feb 23 02:54:44 volumio volumio[10196]: info: ControllerMpd::onStart: Initializing MPD Feb 23 02:54:44 volumio volumio[10196]: info: Creating MPD Configuration file Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:44 volumio volumio[10196]: info: [1771815284838] CoreMusicLibrary::Adding element Media Servers Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:44 volumio volumio[10196]: info: UPNP Browser: Client initialized successfully Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:44 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" 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]" Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" 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]" Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" 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]" Feb 23 02:54:44 volumio sudo[10341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:54:44 volumio sudo[10343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:54:44 volumio sudo[10341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:44 volumio volumio[10196]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:44 volumio sudo[10343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:44 volumio go-librespot[10282]: time="2026-02-23T02:54:44Z" level=info msg="zeroconf server listening on port 33923" Feb 23 02:54:44 volumio sudo[10341]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:44 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:54:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:54:44 volumio volumio[10196]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:44 volumio volumio[10196]: info: [1771815284890] CoreMusicLibrary::Adding element Last_100 Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:44 volumio volumio[10196]: info: [1771815284892] CoreMusicLibrary::Adding element Webradio Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:54:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:54:44 volumio volumio[10196]: info: Initializing BBC Radios Feb 23 02:54:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:54:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:54:44 volumio volumio[10278]: Starting albumart workers Feb 23 02:54:44 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:54:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:54:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:54:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:54:44 volumio volumio[10279]: Starting albumart workers Feb 23 02:54:44 volumio volumio[10196]: info: Creating Spotify config file Feb 23 02:54:44 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:54:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:54:45 volumio sudo[10372]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 02:54:45 volumio sudo[10372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 02:54:45 volumio sudo[10372]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:45 volumio volumio[10196]: info: [1771815285118] CoreMusicLibrary::Adding element YouTube Music Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:45 volumio volumio[10196]: Cannot find translation for source YouTube Music Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:45 volumio volumio[10196]: info: [1771815285122] CoreMusicLibrary::Adding element Podcast Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:45 volumio volumio[10196]: Cannot find translation for source YouTube Music Feb 23 02:54:45 volumio volumio[10196]: Cannot find translation for source Podcast Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Starting plugin Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Feb 23 02:54:45 volumio volumio[10196]: info: Volumio Calling Home Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] snd-aloop already loaded Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] No stations database found, creating v2 Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Database loaded at: 2026-02-23T02:54:45.187Z Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Got 21 phrases from file Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Updated metadata blocklist Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Feb 23 02:54:45 volumio go-librespot[10282]: time="2026-02-23T02:54:45Z" level=debug msg="obtained new client token: AABRqUUqeY5kQ89zPZ9CLI+tzpvM9HrjdDAXT2UYLKaFICoTbmSNm743PoMNdW4y7MaRuI6sZDPNDfPdcehezjRT1xdGG7CN3zndfzNTjBsNHYYKcPueXpIeN9DJnSnMwFqkaJcmwLunR/SAOdM+qbluFUr7bKSObKhOGYiUVqRNG8Kcg4WyzraxM4b/AR+E9rYtHlgnjSAmwgKM4ln2asqt1pRhw8qPQkhPIQ1uyE3r9X207gMoR3E=" Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Management server started on port 3456 Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:54:45 volumio volumio[10196]: info: [1771815285240] CoreMusicLibrary::Adding element FM/DAB Radio Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:54:45 volumio volumio[10196]: Cannot find translation for source YouTube Music Feb 23 02:54:45 volumio volumio[10196]: Cannot find translation for source Podcast Feb 23 02:54:45 volumio volumio[10196]: Cannot find translation for source FM/DAB Radio Feb 23 02:54:45 volumio volumio[10196]: info: [RTL-SDR Radio] Plugin started successfully Feb 23 02:54:45 volumio volumio[10196]: info: MPD Permissions set Feb 23 02:54:45 volumio volumio[10196]: info: MPD Permissions set Feb 23 02:54:45 volumio volumio[10196]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:54:45 volumio volumio[10196]: info: CoreStateMachine::pushState Feb 23 02:54:45 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::volumioPushState Feb 23 02:54:45 volumio volumio[10196]: info: Spotify config file written Feb 23 02:54:45 volumio sudo[10401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 02:54:45 volumio sudo[10401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:45 volumio volumio[10196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 02:54:45 volumio systemd[1]: go-librespot-daemon.service: Killing process 10293 (go-librespot) with signal SIGKILL. Feb 23 02:54:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 02:54:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:54:45 volumio volumio[10196]: info: No need to fix Spotify hosts Feb 23 02:54:45 volumio volumio[10196]: info: Starting Shairport Sync Feb 23 02:54:45 volumio volumio[10196]: info: Starting Shairport Sync Feb 23 02:54:45 volumio volumio[10196]: info: Starting Shairport Sync Feb 23 02:54:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:45 volumio sudo[10401]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio go-librespot[10408]: go-librespot daemon starting... Feb 23 02:54:45 volumio sudo[10416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:45 volumio sudo[10416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:45 volumio sudo[10417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:45 volumio sudo[10417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" level=debug msg="app state loaded" Feb 23 02:54:45 volumio sudo[10423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:54:45 volumio sudo[10423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:45 volumio volumio[10196]: info: Volumio called home Feb 23 02:54:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 02:54:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 02:54:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:54:45 volumio systemd[1]: shairport-sync.service: Consumed 1.556s CPU time. Feb 23 02:54:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:54:45 volumio sudo[10417]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio sudo[10416]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio sudo[10423]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio volumio[10196]: info: Shairport-Sync Started Feb 23 02:54:45 volumio volumio[10196]: Error adding Membership: Error: addMembership EINVAL Feb 23 02:54:45 volumio volumio[10196]: info: Shairport-Sync Started Feb 23 02:54:45 volumio volumio[10196]: info: Shairport-Sync Started Feb 23 02:54:45 volumio volumio[10196]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 23 02:54:45 volumio volumio[10196]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:54:45 volumio volumio[10196]: info: Discovery: Found device Volumio Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:45 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:45 volumio volumio[10196]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:45 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" 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]" Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" 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]" Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" 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]" Feb 23 02:54:45 volumio go-librespot[10419]: time="2026-02-23T02:54:45Z" level=info msg="zeroconf server listening on port 46249" Feb 23 02:54:45 volumio mpd[10374]: 2026-02-23T02:54:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 02:54:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 02:54:45 volumio sudo[10343]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio sudo[10333]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:45 volumio volumio[10196]: info: Completed starting Core Plugins Feb 23 02:54:45 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:45 volumio volumio[10196]: info: ----- MyVolumio plugins startup ---- Feb 23 02:54:45 volumio volumio[10196]: info: ------------------------------------------- Feb 23 02:54:45 volumio volumio[10196]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 02:54:45 volumio volumio[10196]: error: MPD error: The expression evaluated to a falsy value: Feb 23 02:54:45 volumio volumio[10196]: assert.ok(self.idling) Feb 23 02:54:45 volumio volumio[10196]: error: The expression evaluated to a falsy value: Feb 23 02:54:45 volumio volumio[10196]: assert.ok(self.idling) Feb 23 02:54:45 volumio volumio[10196]: info: MPD running with PID10374 Feb 23 02:54:45 volumio volumio[10196]: ,establishing connection Feb 23 02:54:45 volumio volumio[10196]: error: updateQueue error: null Feb 23 02:54:45 volumio volumio[10196]: error: updateQueue error: null Feb 23 02:54:46 volumio go-librespot[10419]: time="2026-02-23T02:54:46Z" level=debug msg="obtained new client token: AADduzQNuI28H442Tr7C94krWzAR12iu52Cbtna2hU52K++7e4+oIv/DN1Ig/i9GWRvfzcz2ONxpxv+UX5tS52XtMiVmn8WGvNOmuSiVWxkJHbRKebCSrkFSoeEyKecaAQGs05iUgW/veSEFjHwOhXlnJhpSfeZN5rM+2eOo8Vur7k384juiMCSjpcXO/PjhdKkgRvHyuDUOzx2dGMhwLfLWsoyzBcbVUcOQLSu5+WUQsytciG2fLnXzHw==" Feb 23 02:54:46 volumio go-librespot[10419]: time="2026-02-23T02:54:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:46 volumio go-librespot[10419]: time="2026-02-23T02:54:46Z" level=debug msg="completed keyexchange" Feb 23 02:54:46 volumio go-librespot[10419]: time="2026-02-23T02:54:46Z" level=debug msg="completed challenge" Feb 23 02:54:46 volumio go-librespot[10419]: time="2026-02-23T02:54:46Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:46 volumio volumio-remote-updater[945]: [2026-02-23 02:54:46] [connect] Successful connection Feb 23 02:54:46 volumio volumio-remote-updater[945]: [2026-02-23 02:54:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771815286 101 Feb 23 02:54:46 volumio volumio[10196]: 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 Feb 23 02:54:46 volumio sudo[10235]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=debug msg="completed keyexchange" Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=debug msg="completed challenge" Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=debug msg="completed keyexchange" Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=debug msg="completed challenge" Feb 23 02:54:47 volumio go-librespot[10419]: time="2026-02-23T02:54:47Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:48 volumio go-librespot[10419]: time="2026-02-23T02:54:48Z" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Feb 23 02:54:48 volumio volumio[10196]: info: go-librespot daemon successfully initialized Feb 23 02:54:48 volumio go-librespot[10419]: time="2026-02-23T02:54:48Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 23 02:54:48 volumio go-librespot[10419]: time="2026-02-23T02:54:48Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 23 02:54:48 volumio go-librespot[10419]: time="2026-02-23T02:54:48Z" level=debug msg="completed keyexchange" Feb 23 02:54:48 volumio go-librespot[10419]: time="2026-02-23T02:54:48Z" level=debug msg="completed challenge" Feb 23 02:54:49 volumio go-librespot[10419]: time="2026-02-23T02:54:49Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:49 volumio go-librespot[10419]: time="2026-02-23T02:54:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:49 volumio go-librespot[10419]: time="2026-02-23T02:54:49Z" level=debug msg="completed keyexchange" Feb 23 02:54:49 volumio go-librespot[10419]: time="2026-02-23T02:54:49Z" level=debug msg="completed challenge" Feb 23 02:54:49 volumio go-librespot[10419]: time="2026-02-23T02:54:49Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:49 volumio volumio[10196]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:54:49 volumio volumio[10196]: info: Discovery: Found device Volumio Feb 23 02:54:49 volumio volumio[10196]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:49 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:50 volumio go-librespot[10419]: time="2026-02-23T02:54:50Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:50 volumio go-librespot[10419]: time="2026-02-23T02:54:50Z" level=debug msg="completed keyexchange" Feb 23 02:54:50 volumio go-librespot[10419]: time="2026-02-23T02:54:50Z" level=debug msg="completed challenge" Feb 23 02:54:50 volumio go-librespot[10419]: time="2026-02-23T02:54:50Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:50 volumio go-librespot[10419]: time="2026-02-23T02:54:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:51 volumio volumio[10196]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:51 volumio volumio[10196]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 02:54:53 volumio sudo[10468]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:53 volumio sudo[10468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:53 volumio sudo[10470]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:53 volumio sudo[10468]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:53 volumio sudo[10470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:53 volumio sudo[10470]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:53 volumio sudo[10473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 02:54:53 volumio sudo[10473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:53 volumio sudo[10473]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:53 volumio volumio[10196]: info: Upmpdcli Daemon Started Feb 23 02:54:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 23 02:54:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:54:53 volumio go-librespot[10476]: go-librespot daemon starting... Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=debug msg="app state loaded" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" 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]" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" 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]" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" 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]" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=info msg="zeroconf server listening on port 36119" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=debug msg="obtained new client token: AADLM1+Efq/YTXUlXiJQBTyeqbJntc7ofeGm1R1W7JCGBrU6DuxYsaJnqEA/nxC/ypR3h2lzUlZ54sApiEbHCVn4/Xn0O97bGWxzQGtMrbJwL4bkzdluQFkKar+wR7K2bH1cOi5D5YmqsGC8hMWKnjdYKkvtYvgHuAkwvwyAna4lD67EaKOPIeblzxAPibzVx4rEUS1GzZXrxg4ZDFTUi9lvPhf4lrHK7bo6LJjCCjR/mrDx75KdBpEuHA==" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=debug msg="completed keyexchange" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=debug msg="completed challenge" Feb 23 02:54:53 volumio go-librespot[10477]: time="2026-02-23T02:54:53Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="completed keyexchange" Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="completed challenge" Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 02:54:54 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:54 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:54 volumio volumio[10196]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 02:54:54 volumio volumio[10196]: info: MyVolumio login type: Token Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 02:54:54 volumio volumio[10196]: info: Streaming services startup Feb 23 02:54:54 volumio volumio[10196]: info: Starting Streaming Daemon Feb 23 02:54:54 volumio sudo[10488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:54 volumio sudo[10488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:54 volumio volumio[10196]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 02:54:54 volumio sudo[10488]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:54 volumio volumio[10196]: info: Initializing connection to go-librespot Websocket Feb 23 02:54:54 volumio volumio[10196]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:54 volumio volumio[10196]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:54 volumio volumio[10196]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="new websocket client" Feb 23 02:54:54 volumio volumio[10196]: info: Connection to go-librespot Websocket established Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="completed keyexchange" Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=debug msg="completed challenge" Feb 23 02:54:54 volumio go-librespot[10477]: time="2026-02-23T02:54:54Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:55 volumio volumio[10196]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 23 02:54:55 volumio volumio[10196]: info: MyVolumio token set successfully Feb 23 02:54:55 volumio volumio[10196]: info: MYVOLUMIO: Adding device Feb 23 02:54:55 volumio volumio[10196]: info: MYVOLUMIO: Evaluating Server Feb 23 02:54:55 volumio go-librespot[10477]: time="2026-02-23T02:54:55Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 23 02:54:55 volumio go-librespot[10477]: time="2026-02-23T02:54:55Z" level=debug msg="completed keyexchange" Feb 23 02:54:55 volumio go-librespot[10477]: time="2026-02-23T02:54:55Z" level=debug msg="completed challenge" Feb 23 02:54:55 volumio volumio[10196]: info: MyVolumio status changed Feb 23 02:54:55 volumio volumio[10196]: info: Streaming services startup Feb 23 02:54:55 volumio volumio[10196]: info: Starting Streaming Daemon Feb 23 02:54:55 volumio volumio[10196]: info: Removing browser output: myVolumio user plan is not superstar Feb 23 02:54:55 volumio volumio[10196]: info: Removing audio output: Feb 23 02:54:55 volumio volumio[10196]: info: Stoppping Tunnel 1 Feb 23 02:54:55 volumio sudo[10517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:54:55 volumio sudo[10517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:55 volumio sudo[10519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 23 02:54:55 volumio sudo[10519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:55 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. Feb 23 02:54:55 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. Feb 23 02:54:55 volumio sudo[10517]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:55 volumio volumio[10196]: error: Cannot start Volumio Streaming Daemon Feb 23 02:54:55 volumio volumio[10196]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 02:54:55 volumio volumio[10196]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 02:54:55 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. Feb 23 02:54:55 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. Feb 23 02:54:55 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. Feb 23 02:54:55 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. Feb 23 02:54:55 volumio sudo[10519]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:55 volumio volumio[10196]: info: Remote SSH Stopped Feb 23 02:54:55 volumio go-librespot[10477]: time="2026-02-23T02:54:55Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:55 volumio volumio[10196]: info: Setting Geolocation for MyVolumio to eu3 Feb 23 02:54:55 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:55 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:55 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:56 volumio go-librespot[10477]: time="2026-02-23T02:54:56Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 23 02:54:56 volumio go-librespot[10477]: time="2026-02-23T02:54:56Z" level=debug msg="completed keyexchange" Feb 23 02:54:56 volumio go-librespot[10477]: time="2026-02-23T02:54:56Z" level=debug msg="completed challenge" Feb 23 02:54:56 volumio volumio[10196]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 23 02:54:56 volumio go-librespot[10477]: time="2026-02-23T02:54:56Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:56 volumio volumio[10196]: info: Updating MyVolumio device info Feb 23 02:54:56 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:56 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:56 volumio volumio[10196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:54:57 volumio volumio[10196]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 23 02:54:57 volumio go-librespot[10477]: time="2026-02-23T02:54:57Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 23 02:54:57 volumio go-librespot[10477]: time="2026-02-23T02:54:57Z" level=debug msg="completed keyexchange" Feb 23 02:54:57 volumio go-librespot[10477]: time="2026-02-23T02:54:57Z" level=debug msg="completed challenge" Feb 23 02:54:57 volumio volumio[10196]: info: Getting Spotify volume Feb 23 02:54:57 volumio volumio[10196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 23 02:54:57 volumio volumio[10196]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:57 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:57 volumio volumio[10196]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Feb 23 02:54:57 volumio volumio[10196]: SPOTIFY: SPOTIFY VOLUME undefined Feb 23 02:54:57 volumio volumio[10196]: SPOTIFY: VOLUMIO VOLUME 0 Feb 23 02:54:57 volumio volumio[10196]: info: Aligning Spotify Volume to Volumio Volume Feb 23 02:54:57 volumio volumio[10196]: info: CoreCommandRouter::volumioGetState Feb 23 02:54:57 volumio volumio[10196]: info: CorePlayQueue::getTrack 0 Feb 23 02:54:57 volumio volumio[10196]: info: Setting Spotify Volume from Volumio: 0 Feb 23 02:54:57 volumio go-librespot[10477]: time="2026-02-23T02:54:57Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:57 volumio go-librespot[10477]: time="2026-02-23T02:54:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:54:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:54:57 volumio volumio[10196]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:57 volumio volumio[10196]: Error: socket hang up Feb 23 02:54:57 volumio volumio[10196]: at connResetException (node:internal/errors:720:14) Feb 23 02:54:57 volumio volumio[10196]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 23 02:54:57 volumio volumio[10196]: at Socket.emit (node:events:526:35) Feb 23 02:54:57 volumio volumio[10196]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 23 02:54:57 volumio volumio[10196]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 23 02:54:57 volumio volumio[10196]: code: 'ECONNRESET', Feb 23 02:54:57 volumio volumio[10196]: response: undefined Feb 23 02:54:57 volumio volumio[10196]: } Feb 23 02:54:57 volumio volumio[10196]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:54:58 volumio sudo[10536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 02:53' Feb 23 02:54:58 volumio sudo[10536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:58 volumio sudo[10536]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:58 volumio volumio-remote-updater[945]: [2026-02-23 02:54:58] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 23 02:54:58 volumio volumio-remote-updater[945]: [2026-02-23 02:54:58] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 23 02:54:58 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:54:58 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 23 02:54:58 volumio systemd[1]: volumio.service: Consumed 8.967s CPU time. Feb 23 02:54:58 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:58 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:58 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8584. Feb 23 02:54:58 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 02:54:58 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 23 02:54:58 volumio systemd[1]: volumio.service: Consumed 8.967s CPU time. Feb 23 02:54:58 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 23 02:54:58 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 02:54:58 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:54:58 volumio volumio[10549]: info: ----- Volumio3 ---- Feb 23 02:54:58 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:54:58 volumio volumio[10549]: info: ----- System startup ---- Feb 23 02:54:58 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:54:59 volumio volumio[10549]: info: MYVOLUMIO Environment detected Feb 23 02:54:59 volumio volumio[10549]: info: Plugin folders cleanup Feb 23 02:54:59 volumio volumio[10549]: info: Scanning into folder /volumio/app/plugins/ Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category audio_interface Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category miscellanea Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category music_service Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category plugins.json Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category system_controller Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category user_interface Feb 23 02:54:59 volumio volumio[10549]: info: Scanning into folder /data/plugins/ Feb 23 02:54:59 volumio volumio[10549]: info: Scanning category music_service Feb 23 02:54:59 volumio volumio[10549]: info: Plugin folders cleanup completed Feb 23 02:54:59 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:54:59 volumio volumio[10549]: info: ----- Core plugins startup ---- Feb 23 02:54:59 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 02:54:59 volumio volumio[10549]: info: Adding plugin upnp to MyMusic Plugins Feb 23 02:54:59 volumio volumio[10549]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 02:54:59 volumio volumio[10549]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugins from folder /data/plugins/ Feb 23 02:54:59 volumio volumio[10549]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "system"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "appearance"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "network"... Feb 23 02:54:59 volumio volumio[10549]: info: Refreshing Cached IP Addresses Feb 23 02:54:59 volumio sudo[10577]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:54:59 volumio sudo[10577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:59 volumio sudo[10579]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:54:59 volumio sudo[10579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:59 volumio sudo[10577]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:59 volumio sudo[10579]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "services"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "alsa_controller"... Feb 23 02:54:59 volumio sudo[10588]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 02:54:59 volumio sudo[10588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:59 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "wizard"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "networkfs"... Feb 23 02:54:59 volumio volumio[10549]: info: Starting Udev Watcher for removable devices Feb 23 02:54:59 volumio volumio[10549]: info: Mounting Device 0ACB-A1DE Feb 23 02:54:59 volumio sudo[10616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Feb 23 02:54:59 volumio sudo[10616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:54:59 volumio sudo[10616]: pam_unix(sudo:session): session closed for user root Feb 23 02:54:59 volumio volumio[10549]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:59 volumio volumio[10549]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:59 volumio volumio[10549]: 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 Feb 23 02:54:59 volumio volumio[10549]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Feb 23 02:54:59 volumio volumio[10549]: dmesg(1) may have more information after failed mount system call. Feb 23 02:54:59 volumio volumio[10549]: info: Ignoring mount for partition: boot Feb 23 02:54:59 volumio volumio[10549]: info: Ignoring mount for partition: volumio Feb 23 02:54:59 volumio volumio[10549]: info: Ignoring mount for partition: volumio_data Feb 23 02:54:59 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "volumio_command_line_client"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "upnp"... Feb 23 02:54:59 volumio volumio[10549]: info: [1771815299606] Starting Upmpd Daemon Feb 23 02:54:59 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "my_music"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "mpd"... Feb 23 02:54:59 volumio volumio[10549]: info: Loading plugin "upnp_browser"... Feb 23 02:55:00 volumio volumio[10549]: info: Starting UPNP Browser Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "alarm-clock"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "airplay_emulation"... Feb 23 02:55:00 volumio volumio[10549]: info: Starting Shairport Sync Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "last_100"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "webradio"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "i2s_dacs"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "volumiodiscovery"... Feb 23 02:55:00 volumio volumio[10549]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:55:00 volumio volumio[10549]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:55:00 volumio volumio[10549]: *** WARNING *** For more information see Feb 23 02:55:00 volumio volumio[10549]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:55:00 volumio volumio[10549]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:55:00 volumio volumio[10549]: *** WARNING *** For more information see Feb 23 02:55:00 volumio node[10549]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 02:55:00 volumio node[10549]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:55:00 volumio node[10549]: *** WARNING *** For more information see Feb 23 02:55:00 volumio node[10549]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 02:55:00 volumio node[10549]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 02:55:00 volumio node[10549]: *** WARNING *** For more information see Feb 23 02:55:00 volumio volumio[10549]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 02:55:00 volumio volumio[10549]: info: Discovery: Started advertising with name: Volumio Feb 23 02:55:00 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "spop"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "ytmusic"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "outputs"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "albumart"... Feb 23 02:55:00 volumio volumio[10549]: info: Plugin example_plugin is not enabled Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "inputs"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "updater_comm"... Feb 23 02:55:00 volumio volumio[10549]: info: Plugin mpdemulation is not enabled Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "rest_api"... Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "websocket"... Feb 23 02:55:00 volumio volumio[10549]: info: Starting Socket.io Server version 1.7.4 Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "podcast"... Feb 23 02:55:00 volumio volumio[10549]: info: ControllerPodcast::constructor Feb 23 02:55:00 volumio volumio[10549]: info: Loading plugin "rtlsdr_radio"... Feb 23 02:55:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 23 02:55:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:55:00 volumio volumio[10620]: Forking 3 albumart workers Feb 23 02:55:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:55:00 volumio go-librespot[10630]: go-librespot daemon starting... Feb 23 02:55:00 volumio go-librespot[10634]: time="2026-02-23T02:55:00Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:55:00 volumio go-librespot[10634]: time="2026-02-23T02:55:00Z" level=debug msg="app state loaded" Feb 23 02:55:00 volumio go-librespot[10634]: time="2026-02-23T02:55:00Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:55:01 volumio volumio[10549]: info: Loading i18n strings for locale en Feb 23 02:55:01 volumio volumio[10549]: Updating browse sources language Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::initPlayerControls Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: Express server listening on port 3000 Feb 23 02:55:01 volumio volumio[10549]: [Metrics] WebUI: 2s 290.38ms Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::resetVolumioState Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::getcurrentVolume Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:55:01 volumio volumio[10549]: info: Volumio Network Manager: Network status updated: 2 Feb 23 02:55:01 volumio volumio[10549]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::pushState Feb 23 02:55:01 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioPushState Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::updateTrackBlock Feb 23 02:55:01 volumio volumio[10549]: info: CorePlayQueue::getTrackBlock Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: Reloading queue from file Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::setRepeat null single undefined Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::pushState Feb 23 02:55:01 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioPushState Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::setRandom true Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::pushState Feb 23 02:55:01 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioPushState Feb 23 02:55:01 volumio volumio[10549]: info: Setting Device type: Raspberry PI Feb 23 02:55:01 volumio volumio[10549]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 23 02:55:01 volumio volumio[10549]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Feb 23 02:55:01 volumio volumio[10549]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 23 02:55:01 volumio volumio[10549]: info: Completed loading Core Plugins Feb 23 02:55:01 volumio volumio[10549]: info: Preparing to generate the ALSA configuration file Feb 23 02:55:01 volumio volumio[10549]: info: VolumeController:: Volume=36 Mute =true Feb 23 02:55:01 volumio volumio[10549]: info: CoreStateMachine::pushState Feb 23 02:55:01 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioPushState Feb 23 02:55:01 volumio go-librespot[10634]: time="2026-02-23T02:55:01Z" 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]" Feb 23 02:55:01 volumio go-librespot[10634]: time="2026-02-23T02:55:01Z" 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]" Feb 23 02:55:01 volumio go-librespot[10634]: time="2026-02-23T02:55:01Z" 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]" Feb 23 02:55:01 volumio volumio[10549]: info: Asound.conf file unchanged, so no further update is needed Feb 23 02:55:01 volumio volumio[10549]: info: Output device has changed, restarting MPD Feb 23 02:55:01 volumio volumio[10632]: Starting albumart workers Feb 23 02:55:01 volumio go-librespot[10634]: time="2026-02-23T02:55:01Z" level=info msg="zeroconf server listening on port 34309" Feb 23 02:55:01 volumio volumio[10549]: info: Output device has changed, restarting Shairport Sync Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio volumio[10633]: Starting albumart workers Feb 23 02:55:01 volumio sudo[10686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:55:01 volumio sudo[10686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio sudo[10686]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio sudo[10688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:55:01 volumio sudo[10688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio volumio[10549]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:55:01 volumio volumio[10549]: info: ___________ START PLUGINS ___________ Feb 23 02:55:01 volumio volumio[10549]: info: ControllerMpd::onStart: Initializing MPD Feb 23 02:55:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 02:55:01 volumio volumio[10549]: info: Creating MPD Configuration file Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:55:01 volumio volumio[10549]: info: [1771815301406] CoreMusicLibrary::Adding element Media Servers Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio sudo[10696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 02:55:01 volumio volumio[10549]: info: UPNP Browser: Client initialized successfully Feb 23 02:55:01 volumio sudo[10696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio sudo[10698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 02:55:01 volumio sudo[10698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:55:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:55:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:55:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:55:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:55:01 volumio sudo[10696]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:55:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:55:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 02:55:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 02:55:01 volumio volumio[10549]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 02:55:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 02:55:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 02:55:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 02:55:01 volumio volumio[10631]: Starting albumart workers Feb 23 02:55:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 02:55:01 volumio volumio[10549]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:55:01 volumio volumio[10549]: info: [1771815301488] CoreMusicLibrary::Adding element Last_100 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:55:01 volumio volumio[10549]: info: [1771815301493] CoreMusicLibrary::Adding element Webradio Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:55:01 volumio volumio[10549]: info: Initializing BBC Radios Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio sudo[10712]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 02:55:01 volumio sudo[10712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 02:55:01 volumio volumio[10549]: info: Creating Spotify config file Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio sudo[10712]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio go-librespot[10634]: time="2026-02-23T02:55:01Z" level=debug msg="obtained new client token: AABpzc0RYtn5iLO88FRtsiMdzCLZMUH68edyogON5gEHBWGW7BH3emqnPoGJvsGH4XbSSL7PoaPXIXk6GkYPK84hH4swKQPEgFZtKlL+0Wz3m2jyFts9FMw0RQrgnmcPBqHM11GlaAN0mv3l5IHZrp14SK0YDQhILy7C/g/XAqZJTI5m2qR/p9v7ZeRl33FKY8WT3m+XKCST5atUT30er76tSEAvDqWTgrcCW5vlMW+rCpa8++HFZaK/CA==" Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:55:01 volumio volumio[10549]: info: [1771815301697] CoreMusicLibrary::Adding element YouTube Music Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio volumio[10549]: Cannot find translation for source YouTube Music Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:55:01 volumio volumio[10549]: info: [1771815301701] CoreMusicLibrary::Adding element Podcast Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio volumio[10549]: Cannot find translation for source YouTube Music Feb 23 02:55:01 volumio volumio[10549]: Cannot find translation for source Podcast Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Starting plugin Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Feb 23 02:55:01 volumio volumio[10549]: info: Volumio Calling Home Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] snd-aloop already loaded Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] No stations database found, creating v2 Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Database loaded at: 2026-02-23T02:55:01.760Z Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Got 21 phrases from file Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Updated metadata blocklist Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Management server started on port 3456 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 02:55:01 volumio volumio[10549]: info: [1771815301793] CoreMusicLibrary::Adding element FM/DAB Radio Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 02:55:01 volumio volumio[10549]: Cannot find translation for source YouTube Music Feb 23 02:55:01 volumio volumio[10549]: Cannot find translation for source Podcast Feb 23 02:55:01 volumio volumio[10549]: Cannot find translation for source FM/DAB Radio Feb 23 02:55:01 volumio volumio[10549]: info: [RTL-SDR Radio] Plugin started successfully Feb 23 02:55:01 volumio volumio[10549]: info: MPD Permissions set Feb 23 02:55:01 volumio volumio[10549]: info: MPD Permissions set Feb 23 02:55:01 volumio volumio[10549]: info: Spotify config file written Feb 23 02:55:01 volumio sudo[10754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 02:55:01 volumio sudo[10754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio go-librespot[10634]: time="2026-02-23T02:55:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:55:01 volumio volumio[10549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 02:55:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 02:55:01 volumio volumio[10549]: info: No need to fix Spotify hosts Feb 23 02:55:01 volumio volumio[10549]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:55:01 volumio volumio[10549]: info: Discovery: Found device Volumio Feb 23 02:55:01 volumio volumio[10549]: info: CoreCommandRouter::volumioGetState Feb 23 02:55:01 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:55:01 volumio go-librespot[10762]: go-librespot daemon starting... Feb 23 02:55:01 volumio sudo[10754]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio volumio[10549]: info: Starting Shairport Sync Feb 23 02:55:01 volumio volumio[10549]: info: Starting Shairport Sync Feb 23 02:55:01 volumio volumio[10549]: info: Starting Shairport Sync Feb 23 02:55:01 volumio go-librespot[10768]: time="2026-02-23T02:55:01Z" level=info msg="running go-librespot 0.6.2" Feb 23 02:55:01 volumio go-librespot[10768]: time="2026-02-23T02:55:01Z" level=debug msg="app state loaded" Feb 23 02:55:01 volumio go-librespot[10768]: time="2026-02-23T02:55:01Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 02:55:01 volumio sudo[10774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:55:01 volumio sudo[10774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio sudo[10778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:55:01 volumio sudo[10776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 02:55:01 volumio sudo[10778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio sudo[10776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 02:55:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 02:55:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:55:01 volumio systemd[1]: shairport-sync.service: Consumed 1.555s CPU time. Feb 23 02:55:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 02:55:01 volumio sudo[10776]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio sudo[10778]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio sudo[10774]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:01 volumio volumio[10549]: info: Shairport-Sync Started Feb 23 02:55:01 volumio volumio[10549]: Error adding Membership: Error: addMembership EINVAL Feb 23 02:55:01 volumio volumio[10549]: info: Shairport-Sync Started Feb 23 02:55:01 volumio volumio[10549]: info: Shairport-Sync Started Feb 23 02:55:02 volumio volumio[10549]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Feb 23 02:55:02 volumio volumio[10549]: info: Discovery: Found device Volumio Feb 23 02:55:02 volumio volumio[10549]: info: CoreCommandRouter::volumioGetState Feb 23 02:55:02 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:02 volumio volumio[10549]: info: Volumio called home Feb 23 02:55:02 volumio volumio[10549]: info: CoreCommandRouter::volumioGetState Feb 23 02:55:02 volumio volumio[10549]: info: CorePlayQueue::getTrack 0 Feb 23 02:55:02 volumio mpd[10733]: 2026-02-23T02:55:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 02:55:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 02:55:02 volumio sudo[10698]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:02 volumio sudo[10688]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:02 volumio volumio[10549]: info: Completed starting Core Plugins Feb 23 02:55:02 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:55:02 volumio volumio[10549]: info: ----- MyVolumio plugins startup ---- Feb 23 02:55:02 volumio volumio[10549]: info: ------------------------------------------- Feb 23 02:55:02 volumio volumio[10549]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 02:55:02 volumio volumio[10549]: error: MPD error: The expression evaluated to a falsy value: Feb 23 02:55:02 volumio volumio[10549]: assert.ok(self.idling) Feb 23 02:55:02 volumio volumio[10549]: error: The expression evaluated to a falsy value: Feb 23 02:55:02 volumio volumio[10549]: assert.ok(self.idling) Feb 23 02:55:02 volumio volumio[10549]: error: updateQueue error: null Feb 23 02:55:02 volumio volumio[10549]: info: MPD running with PID10733 Feb 23 02:55:02 volumio volumio[10549]: ,establishing connection Feb 23 02:55:02 volumio volumio[10549]: error: updateQueue error: null Feb 23 02:55:02 volumio volumio[10549]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 23 02:55:02 volumio go-librespot[10768]: time="2026-02-23T02:55:02Z" 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]" Feb 23 02:55:02 volumio go-librespot[10768]: time="2026-02-23T02:55:02Z" 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]" Feb 23 02:55:02 volumio go-librespot[10768]: time="2026-02-23T02:55:02Z" 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]" Feb 23 02:55:02 volumio go-librespot[10768]: time="2026-02-23T02:55:02Z" level=info msg="zeroconf server listening on port 39305" Feb 23 02:55:03 volumio go-librespot[10768]: time="2026-02-23T02:55:03Z" level=debug msg="obtained new client token: AAB8ZFnKONHVUIVd/19O/VlMBX4ZD9wMUJPXSUrq+lpSvHH68NzeYplUnakZGRhfpChLhwxYnc3cpKX4A6Ff17ooW9psbrWir1Ud7tnX87FL+ngP+kmyiFbChG1hoUzWoRpEtTNDwPtbrypmOxrMQRtcf61VH738F/QUodPwrHF3JjmZNLJO8it5KQbYaw3U8ajyORbqDz9pkyaaTM5vMVplqv962yO6IoZML7uA4yohx1IQvFa0omq+OQ==" Feb 23 02:55:03 volumio volumio-remote-updater[945]: [2026-02-23 02:55:03] [connect] Successful connection Feb 23 02:55:03 volumio volumio-remote-updater[945]: [2026-02-23 02:55:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771815303 101 Feb 23 02:55:03 volumio volumio[10549]: 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 Feb 23 02:55:03 volumio sudo[10588]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=debug msg="completed keyexchange" Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=debug msg="completed challenge" Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=debug msg="completed keyexchange" Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=debug msg="completed challenge" Feb 23 02:55:04 volumio go-librespot[10768]: time="2026-02-23T02:55:04Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:04 volumio volumio[10549]: info: go-librespot daemon successfully initialized Feb 23 02:55:05 volumio go-librespot[10768]: time="2026-02-23T02:55:05Z" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 23 02:55:05 volumio go-librespot[10768]: time="2026-02-23T02:55:05Z" level=debug msg="completed keyexchange" Feb 23 02:55:05 volumio go-librespot[10768]: time="2026-02-23T02:55:05Z" level=debug msg="completed challenge" Feb 23 02:55:05 volumio go-librespot[10768]: time="2026-02-23T02:55:05Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=debug msg="completed keyexchange" Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=debug msg="completed challenge" Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=debug msg="completed keyexchange" Feb 23 02:55:06 volumio go-librespot[10768]: time="2026-02-23T02:55:06Z" level=debug msg="completed challenge" Feb 23 02:55:07 volumio go-librespot[10768]: time="2026-02-23T02:55:07Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:07 volumio go-librespot[10768]: time="2026-02-23T02:55:07Z" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 23 02:55:07 volumio volumio[10549]: info: Initializing connection to go-librespot Websocket Feb 23 02:55:07 volumio go-librespot[10768]: time="2026-02-23T02:55:07Z" level=debug msg="new websocket client" Feb 23 02:55:07 volumio volumio[10549]: info: Connection to go-librespot Websocket established Feb 23 02:55:08 volumio go-librespot[10768]: time="2026-02-23T02:55:08Z" level=debug msg="completed keyexchange" Feb 23 02:55:08 volumio go-librespot[10768]: time="2026-02-23T02:55:08Z" level=debug msg="completed challenge" Feb 23 02:55:08 volumio go-librespot[10768]: time="2026-02-23T02:55:08Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:08 volumio go-librespot[10768]: time="2026-02-23T02:55:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 02:55:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 02:55:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 02:55:08 volumio volumio[10549]: info: Connection to go-librespot Websocket closed Feb 23 02:55:09 volumio sudo[10821]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 02:55:09 volumio sudo[10821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:09 volumio sudo[10823]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 02:55:09 volumio sudo[10821]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:09 volumio sudo[10823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:09 volumio sudo[10823]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:09 volumio sudo[10827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 02:55:09 volumio sudo[10827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:09 volumio sudo[10827]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:09 volumio volumio[10549]: info: Upmpdcli Daemon Started Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 02:55:10 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:10 volumio volumio[10549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 02:55:10 volumio volumio[10549]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 02:55:10 volumio volumio[10549]: info: MyVolumio login type: Token Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 02:55:10 volumio volumio[10549]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 02:55:11 volumio volumio[10549]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 02:55:11 volumio volumio[10549]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 02:55:11 volumio volumio[10549]: info: Streaming services startup Feb 23 02:55:11 volumio volumio[10549]: info: Starting Streaming Daemon Feb 23 02:55:11 volumio sudo[10830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 02:55:11 volumio sudo[10830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:11 volumio volumio[10549]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 02:55:11 volumio sudo[10830]: pam_unix(sudo:session): session closed for user root Feb 23 02:55:11 volumio volumio[10549]: info: Getting Spotify volume Feb 23 02:55:11 volumio volumio[10549]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:55:11 volumio volumio[10549]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 02:55:11 volumio volumio[10549]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 23 02:55:11 volumio volumio[10549]: errno: -111, Feb 23 02:55:11 volumio volumio[10549]: code: 'ECONNREFUSED', Feb 23 02:55:11 volumio volumio[10549]: syscall: 'connect', Feb 23 02:55:11 volumio volumio[10549]: address: '127.0.0.1', Feb 23 02:55:11 volumio volumio[10549]: port: 9879, Feb 23 02:55:11 volumio volumio[10549]: response: undefined Feb 23 02:55:11 volumio volumio[10549]: } Feb 23 02:55:11 volumio volumio[10549]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 02:55:11 volumio sudo[10850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 02:54' Feb 23 02:55:11 volumio sudo[10850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 02:55:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 23 02:55:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:55:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 02:55:11 volumio go-librespot[10852]: go-librespot daemon starting... 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"