Feb 17 09:36:00 music go-librespot[25271]: time="2026-02-17T09:36:00-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:36:00 music go-librespot[25271]: time="2026-02-17T09:36:00-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:36:00 music volumio[24988]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:36:00 music volumio[24988]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:36:00 music go-librespot[25271]: time="2026-02-17T09:36:00-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:00 music go-librespot[25271]: time="2026-02-17T09:36:00-05:00" level=debug msg="completed challenge" Feb 17 09:36:01 music go-librespot[25271]: time="2026-02-17T09:36:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:01 music go-librespot[25271]: time="2026-02-17T09:36:01-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:36:01 music go-librespot[25271]: time="2026-02-17T09:36:01-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:01 music go-librespot[25271]: time="2026-02-17T09:36:01-05:00" level=debug msg="completed challenge" Feb 17 09:36:01 music volumio[24988]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:36:01 music volumio[24988]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:36:01 music go-librespot[25271]: time="2026-02-17T09:36:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:01 music volumio[24988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:01 music volumio[24988]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:01 music volumio[24988]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:36:01 music volumio[24988]: info: MyVolumio login type: Token Feb 17 09:36:01 music volumio[24988]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:36:01 music volumio[24988]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:36:02 music go-librespot[25271]: time="2026-02-17T09:36:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:02 music go-librespot[25271]: time="2026-02-17T09:36:02-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:02 music go-librespot[25271]: time="2026-02-17T09:36:02-05:00" level=debug msg="completed challenge" Feb 17 09:36:02 music go-librespot[25271]: time="2026-02-17T09:36:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:02 music volumio[24988]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:36:02 music volumio[24988]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:36:02 music volumio[24988]: info: Streaming services startup Feb 17 09:36:02 music volumio[24988]: info: Starting Streaming Daemon Feb 17 09:36:02 music sudo[25282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:36:02 music sudo[25282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:02 music volumio[24988]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:36:02 music sudo[25282]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:02 music volumio[24988]: info: Getting Spotify volume Feb 17 09:36:03 music volumio[24988]: error: Cannot start Volumio Streaming Daemon Feb 17 09:36:03 music volumio[24988]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 09:36:03 music volumio[24988]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 09:36:03 music volumio[24988]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 17 09:36:03 music volumio[24988]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:03 music volumio[24988]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:03 music go-librespot[25271]: time="2026-02-17T09:36:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:03 music volumio[24988]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 Feb 17 09:36:03 music volumio[24988]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 09:36:03 music volumio[24988]: SPOTIFY: VOLUMIO VOLUME 73 Feb 17 09:36:03 music volumio[24988]: info: Aligning Spotify Volume to Volumio Volume Feb 17 09:36:03 music volumio[24988]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:03 music volumio[24988]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:03 music volumio[24988]: info: Setting Spotify Volume from Volumio: 73 Feb 17 09:36:03 music go-librespot[25271]: time="2026-02-17T09:36:03-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:03 music go-librespot[25271]: time="2026-02-17T09:36:03-05:00" level=debug msg="completed challenge" Feb 17 09:36:03 music go-librespot[25271]: time="2026-02-17T09:36:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:03 music go-librespot[25271]: time="2026-02-17T09:36:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:03 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:03 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:03 music volumio[24988]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:36:03 music volumio[24988]: Error: socket hang up Feb 17 09:36:03 music volumio[24988]: at connResetException (node:internal/errors:720:14) Feb 17 09:36:03 music volumio[24988]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 09:36:03 music volumio[24988]: at Socket.emit (node:events:526:35) Feb 17 09:36:03 music volumio[24988]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 09:36:03 music volumio[24988]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 09:36:03 music volumio[24988]: code: 'ECONNRESET', Feb 17 09:36:03 music volumio[24988]: response: undefined Feb 17 09:36:03 music volumio[24988]: } Feb 17 09:36:03 music volumio[24988]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:36:04 music sudo[25317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:35' Feb 17 09:36:04 music sudo[25317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:04 music sudo[25317]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:04 music volumio5-onboarding[32661]: time=2026-02-17T09:36:04.377-05:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 17 09:36:04 music volumio-remote-updater[11935]: [2026-02-17 09:36:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:36:04 music volumio-remote-updater[11935]: [2026-02-17 09:36:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:36:04 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:04 music volumio5-onboarding[32661]: time=2026-02-17T09:36:04.383-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:36:04 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:36:04 music systemd[1]: volumio.service: Consumed 26.760s CPU time. Feb 17 09:36:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:36:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:36:04 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3244. Feb 17 09:36:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:36:04 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:36:04 music systemd[1]: volumio.service: Consumed 26.760s CPU time. Feb 17 09:36:04 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:36:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:36:05 music volumio5-onboarding[32661]: time=2026-02-17T09:36:05.385-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:36:06 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 09:36:06 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:06 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:06 music volumio[25329]: info: ----- Volumio3 ---- Feb 17 09:36:06 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:06 music volumio[25329]: info: ----- System startup ---- Feb 17 09:36:06 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:06 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:06 music go-librespot[25350]: go-librespot daemon starting... Feb 17 09:36:06 music go-librespot[25351]: time="2026-02-17T09:36:06-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:06 music go-librespot[25351]: time="2026-02-17T09:36:06-05:00" level=debug msg="app state loaded" Feb 17 09:36:06 music go-librespot[25351]: time="2026-02-17T09:36:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=info msg="zeroconf server listening on port 43431" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=debug msg="obtained new client token: AADIufjoiVlHjSUeeqLHgU5Yvsk0ftwOqL2xbRI54KoDVT0E4+VpFuZpgZMnrcIKheYTX3LtdNu9D+oMDx9yyoeUnVNnVC2+/ddsJG6EjCznAdFCMIaJyhh2/hmOxJ8DhTVZCYlJH88kOEKQT2IqKIHCQQQVt6jWlOaguV+WJn0rCLRV9hHdLZyu1R3hF85eWCtVVyMc+wlUpJSCCK7BVnSTUsKo6dvOwCMiwoUOvLExW2dwV2dG" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:07 music volumio[25329]: info: MYVOLUMIO Environment detected Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=debug msg="completed challenge" Feb 17 09:36:07 music volumio[25329]: info: Plugin folders cleanup Feb 17 09:36:07 music volumio[25329]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:36:07 music volumio[25329]: info: Scanning category audio_interface Feb 17 09:36:07 music volumio[25329]: info: Scanning category miscellanea Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:07 music volumio[25329]: info: Scanning category music_service Feb 17 09:36:07 music volumio[25329]: info: Scanning category plugins.json Feb 17 09:36:07 music volumio[25329]: info: Scanning category system_controller Feb 17 09:36:07 music volumio[25329]: info: Scanning category user_interface Feb 17 09:36:07 music volumio[25329]: info: Scanning into folder /data/plugins/ Feb 17 09:36:07 music volumio[25329]: info: Scanning category music_service Feb 17 09:36:07 music volumio[25329]: info: Plugin folders cleanup completed Feb 17 09:36:07 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:07 music volumio[25329]: info: ----- Core plugins startup ---- Feb 17 09:36:07 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:07 music volumio[25329]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:36:07 music volumio[25329]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:36:07 music volumio[25329]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:36:07 music volumio[25329]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:36:07 music volumio[25329]: info: Loading plugins from folder /data/plugins/ Feb 17 09:36:07 music volumio[25329]: info: Loading plugin "system"... Feb 17 09:36:07 music volumio[25329]: info: Loading plugin "appearance"... Feb 17 09:36:07 music go-librespot[25351]: time="2026-02-17T09:36:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=debug msg="completed challenge" Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "network"... Feb 17 09:36:08 music volumio[25329]: info: Refreshing Cached IP Addresses Feb 17 09:36:08 music sudo[25368]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:36:08 music sudo[25368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:08 music sudo[25370]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:36:08 music sudo[25368]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:08 music sudo[25370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "services"... Feb 17 09:36:08 music sudo[25370]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "volumio5onboarding"... Feb 17 09:36:08 music sudo[25378]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:36:08 music sudo[25378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "alsa_controller"... Feb 17 09:36:08 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "wizard"... Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "networkfs"... Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:08 music volumio[25329]: info: Starting Udev Watcher for removable devices Feb 17 09:36:08 music volumio[25329]: info: Ignoring mount for partition: boot Feb 17 09:36:08 music volumio[25329]: info: Ignoring mount for partition: volumio Feb 17 09:36:08 music volumio[25329]: info: Ignoring mount for partition: volumio_data Feb 17 09:36:08 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "upnp"... Feb 17 09:36:08 music volumio[25329]: info: [1771338968784] Starting Upmpd Daemon Feb 17 09:36:08 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "my_music"... Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=debug msg="completed challenge" Feb 17 09:36:08 music volumio[25329]: info: Loading plugin "mpd"... Feb 17 09:36:08 music go-librespot[25351]: time="2026-02-17T09:36:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:09 music volumio[25329]: info: Loading plugin "upnp_browser"... Feb 17 09:36:09 music sudo[25378]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:09 music volumio-remote-updater[11935]: [2026-02-17 09:36:09] [connect] Successful connection Feb 17 09:36:09 music go-librespot[25351]: time="2026-02-17T09:36:09-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:36:09 music go-librespot[25351]: time="2026-02-17T09:36:09-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:09 music go-librespot[25351]: time="2026-02-17T09:36:09-05:00" level=debug msg="completed challenge" Feb 17 09:36:09 music go-librespot[25351]: time="2026-02-17T09:36:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:10 music go-librespot[25351]: time="2026-02-17T09:36:10-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 17 09:36:10 music go-librespot[25351]: time="2026-02-17T09:36:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:58344->104.199.65.9:443: read: connection reset by peer" Feb 17 09:36:10 music volumio[25329]: info: Starting UPNP Browser Feb 17 09:36:10 music volumio[25329]: info: Loading plugin "alarm-clock"... Feb 17 09:36:10 music volumio[25329]: info: Loading plugin "airplay_emulation"... Feb 17 09:36:10 music go-librespot[25351]: time="2026-02-17T09:36:10-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:36:10 music volumio[25329]: info: Starting Shairport Sync Feb 17 09:36:10 music volumio[25329]: info: Loading plugin "last_100"... Feb 17 09:36:10 music volumio[25329]: info: Loading plugin "webradio"... Feb 17 09:36:10 music volumio[25329]: info: Loading plugin "i2s_dacs"... Feb 17 09:36:10 music volumio[25329]: info: I2S DAC not set, start Auto-detection Feb 17 09:36:10 music volumio[25329]: info: Loading plugin "volumiodiscovery"... Feb 17 09:36:10 music go-librespot[25351]: time="2026-02-17T09:36:10-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:10 music go-librespot[25351]: time="2026-02-17T09:36:10-05:00" level=debug msg="completed challenge" Feb 17 09:36:11 music volumio[25329]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:11 music volumio[25329]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:11 music volumio[25329]: *** WARNING *** For more information see Feb 17 09:36:11 music volumio[25329]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:11 music volumio[25329]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:11 music volumio[25329]: *** WARNING *** For more information see Feb 17 09:36:11 music node[25329]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:11 music node[25329]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:11 music node[25329]: *** WARNING *** For more information see Feb 17 09:36:11 music node[25329]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:11 music node[25329]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:11 music node[25329]: *** WARNING *** For more information see Feb 17 09:36:11 music volumio[25329]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:36:11 music volumio[25329]: info: Discovery: Started advertising with name: music Feb 17 09:36:11 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:36:11 music volumio[25329]: info: Loading plugin "spop"... Feb 17 09:36:11 music go-librespot[25351]: time="2026-02-17T09:36:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:11 music go-librespot[25351]: time="2026-02-17T09:36:11-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:11 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:11 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:12 music volumio[25329]: info: Loading plugin "outputs"... Feb 17 09:36:12 music volumio[25329]: info: Loading plugin "albumart"... Feb 17 09:36:12 music volumio[25329]: info: Plugin example_plugin is not enabled Feb 17 09:36:12 music volumio[25329]: info: Loading plugin "inputs"... Feb 17 09:36:12 music volumio[25329]: info: Loading plugin "updater_comm"... Feb 17 09:36:12 music volumio[25329]: info: Plugin mpdemulation is not enabled Feb 17 09:36:12 music volumio[25329]: info: Loading plugin "rest_api"... Feb 17 09:36:12 music volumio[25329]: info: Loading plugin "websocket"... Feb 17 09:36:12 music volumio[25329]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:36:12 music volumio[25329]: info: Loading i18n strings for locale en Feb 17 09:36:12 music volumio[25329]: Updating browse sources language Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::initPlayerControls Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:36:12 music volumio[25329]: Express server listening on port 3000 Feb 17 09:36:12 music volumio[25329]: [Metrics] WebUI: 6s 518.83ms Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::resetVolumioState Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::getcurrentVolume Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:12 music volumio[25329]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:36:12 music volumio[25329]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 09:36:12 music volumio[25403]: Forking 3 albumart workers Feb 17 09:36:12 music volumio[25329]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::pushState Feb 17 09:36:12 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::updateTrackBlock Feb 17 09:36:12 music volumio[25329]: info: CorePlayQueue::getTrackBlock Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:36:12 music volumio[25329]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 17 09:36:12 music volumio[25329]: info: Reloading queue from file Feb 17 09:36:12 music volumio-remote-updater[11935]: [2026-02-17 09:36:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771338969 101 Feb 17 09:36:12 music volumio[25329]: 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 17 09:36:12 music volumio[25329]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::pushState Feb 17 09:36:12 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::setRandom null Feb 17 09:36:12 music volumio[25329]: info: CoreStateMachine::pushState Feb 17 09:36:12 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:12 music volumio[25329]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:12 music volumio[25329]: info: Setting Device type: Raspberry PI Feb 17 09:36:13 music volumio[25329]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 17 09:36:13 music volumio[25329]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 17 09:36:13 music volumio[25329]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:36:13 music volumio[25329]: info: CoreStateMachine::pushState Feb 17 09:36:13 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:13 music volumio[25329]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 17 09:36:13 music volumio[25329]: info: Received Get System Info Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:36:13 music volumio[25329]: info: Discovery: Getting this device information Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:13 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 17 09:36:13 music volumio[25329]: info: Completed loading Core Plugins Feb 17 09:36:13 music volumio[25329]: info: Preparing to generate the ALSA configuration file Feb 17 09:36:13 music volumio[25329]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:36:13 music volumio[25329]: info: Discovery: Found device music Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:13 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:13 music volumio[25329]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:36:13 music volumio[25329]: info: Discovery: Found device music Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:13 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:13 music volumio[25329]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:36:13 music volumio[25329]: info: Output device has changed, restarting MPD Feb 17 09:36:13 music volumio[25329]: info: Output device has changed, restarting Shairport Sync Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:13 music sudo[25457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:36:13 music sudo[25457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:13 music sudo[25457]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:13 music volumio[25329]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:36:13 music volumio[25329]: info: ___________ START PLUGINS ___________ Feb 17 09:36:13 music sudo[25459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:36:13 music sudo[25459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:13 music volumio[25329]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:36:13 music volumio[25329]: info: Creating MPD Configuration file Feb 17 09:36:13 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:36:13 music sudo[25467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 17 09:36:13 music sudo[25467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:36:13 music sudo[25469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:13 music volumio[25329]: info: [1771338973385] CoreMusicLibrary::Adding element Media Servers Feb 17 09:36:13 music sudo[25469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:13 music sudo[25469]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:13 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:36:13 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:36:13 music systemd[1]: mpd.service: Consumed 4.145s CPU time. Feb 17 09:36:13 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:36:13 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:36:13 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:36:13 music volumio[25329]: info: UPNP Browser: Client initialized successfully Feb 17 09:36:13 music sudo[25472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:36:13 music sudo[25472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:13 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:36:13 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:36:13 music volumio[25329]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:13 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:36:13 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:36:13 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:36:13 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:36:13 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:36:13 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:36:13 music volumio[25329]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:36:13 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:13 music volumio[25329]: info: [1771338973629] CoreMusicLibrary::Adding element Last_100 Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:13 music volumio[25329]: info: [1771338973639] CoreMusicLibrary::Adding element Webradio Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:36:13 music volumio[25329]: info: Initializing BBC Radios Feb 17 09:36:13 music sudo[25467]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:13 music volumio[25329]: info: Creating Spotify config file Feb 17 09:36:13 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:13 music sudo[25486]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:36:13 music sudo[25486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:36:13 music sudo[25486]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:14 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 09:36:14 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:14 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:14 music go-librespot[25502]: go-librespot daemon starting... Feb 17 09:36:14 music go-librespot[25503]: time="2026-02-17T09:36:14-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:14 music volumio[25329]: info: Volumio Calling Home Feb 17 09:36:14 music volumio[25419]: Starting albumart workers Feb 17 09:36:14 music volumio[25420]: Starting albumart workers Feb 17 09:36:14 music go-librespot[25503]: time="2026-02-17T09:36:14-05:00" level=info msg="zeroconf server listening on port 43561" Feb 17 09:36:14 music volumio[25418]: Starting albumart workers Feb 17 09:36:15 music volumio[25329]: info: MPD Permissions set Feb 17 09:36:15 music volumio[25329]: info: MPD Permissions set Feb 17 09:36:15 music volumio[25329]: info: Spotify config file written Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:15 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:15 music sudo[25516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:36:15 music sudo[25516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:15 music volumio[25329]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 17 09:36:15 music volumio[25329]: info: Volumio called home Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:15 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 09:36:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:15 music go-librespot[25523]: go-librespot daemon starting... Feb 17 09:36:15 music sudo[25516]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=debug msg="app state loaded" Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:15 music volumio[25329]: info: No need to fix Spotify hosts Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:15 music volumio[25329]: info: Listing playlists Feb 17 09:36:15 music volumio[25329]: info: Listing playlists Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:36:15 music go-librespot[25526]: time="2026-02-17T09:36:15-05:00" level=info msg="zeroconf server listening on port 41371" Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="obtained new client token: AAB4bJRHX7XIRd0k9KLfJOl8bfwk6NRqxaB5nDaE0RYojGrBgZGsn+WdSZGub98OMFA0m9T64N2ydmiOsJ3k4afH8MpiZT7i8vXc1j6p6RgmM8z2Juw9tlsC4W/vJj8sTHuNhpiJrbUT1SZhWn3KZM8S88zsU0I64aP6OUlp/GasMHuDVB9llSaOErlaF9YqNjBFZaekUPew7kK4O2AEfNJVKoM9uRWySEagZ09kEMJrFVHge+3q" Feb 17 09:36:16 music volumio[25329]: info: Starting Shairport Sync Feb 17 09:36:16 music volumio[25329]: info: Starting Shairport Sync Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:16 music volumio[25329]: info: Starting Shairport Sync Feb 17 09:36:16 music sudo[25553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:36:16 music sudo[25553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:16 music sudo[25551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:36:16 music sudo[25551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:16 music sudo[25555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:36:16 music sudo[25555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="completed challenge" Feb 17 09:36:16 music volumio[25329]: info: New Spotify access tokenBQBZCBRg5Z... Feb 17 09:36:16 music volumio[25329]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:36:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:36:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:36:16 music systemd[1]: shairport-sync.service: Consumed 1.876s CPU time. Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:16 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:36:16 music sudo[25555]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:16 music volumio[25329]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 17 09:36:16 music sudo[25551]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:16 music sudo[25553]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:16 music volumio[25329]: info: Shairport-Sync Started Feb 17 09:36:16 music volumio[25329]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:36:16 music volumio[25329]: info: Shairport-Sync Started Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 17 09:36:16 music volumio[25329]: info: Shairport-Sync Started Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioGetVisibleSources Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:16 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioGetQueue Feb 17 09:36:16 music volumio[25329]: info: CoreStateMachine::getQueue Feb 17 09:36:16 music volumio[25329]: info: CorePlayQueue::getQueue Feb 17 09:36:16 music volumio[25329]: info: Listing playlists Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 17 09:36:16 music volumio[25329]: info: Received Get System Info Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:36:16 music volumio[25329]: info: Discovery: Getting this device information Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:16 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:16 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:16 music volumio[25329]: SPOTIFY: User informations: {"country":"US","display_name":"Clipinger Sporing Law","email":"maryalyce@cliplaw.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mltxw4dg22kb3gk2jynmhfuwt4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31mltxw4dg22kb3gk2jynmhfuwt4","id":"31mltxw4dg22kb3gk2jynmhfuwt4","images":[],"product":"premium","type":"user","uri":"spotify:user:31mltxw4dg22kb3gk2jynmhfuwt4"} Feb 17 09:36:16 music volumio[25329]: info: Spotify Successfully logged in Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:16 music volumio[25329]: info: [1771338976653] CoreMusicLibrary::Adding element Spotify Feb 17 09:36:16 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:16 music volumio[25329]: Cannot find translation for source Spotify Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:16 music go-librespot[25526]: time="2026-02-17T09:36:16-05:00" level=debug msg="completed challenge" Feb 17 09:36:17 music go-librespot[25526]: time="2026-02-17T09:36:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:17 music go-librespot[25526]: time="2026-02-17T09:36:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:17 music go-librespot[25526]: time="2026-02-17T09:36:17-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:17 music go-librespot[25526]: time="2026-02-17T09:36:17-05:00" level=debug msg="completed challenge" Feb 17 09:36:17 music go-librespot[25526]: time="2026-02-17T09:36:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:18 music mpd[25501]: 2026-02-17T09:36:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:36:18 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:36:18 music sudo[25459]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:18 music sudo[25472]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:18 music volumio[25329]: info: Completed starting Core Plugins Feb 17 09:36:18 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:18 music volumio[25329]: info: ----- MyVolumio plugins startup ---- Feb 17 09:36:18 music volumio[25329]: info: ------------------------------------------- Feb 17 09:36:18 music volumio[25329]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:36:18 music go-librespot[25526]: time="2026-02-17T09:36:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:36:18 music volumio[25329]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:36:18 music volumio[25329]: assert.ok(self.idling) Feb 17 09:36:18 music volumio[25329]: error: The expression evaluated to a falsy value: Feb 17 09:36:18 music volumio[25329]: assert.ok(self.idling) Feb 17 09:36:18 music volumio[25329]: info: MPD running with PID25501 Feb 17 09:36:18 music volumio[25329]: ,establishing connection Feb 17 09:36:18 music volumio[25329]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:36:18 music volumio[25329]: assert.ok(self.idling) Feb 17 09:36:18 music volumio[25329]: error: The expression evaluated to a falsy value: Feb 17 09:36:18 music volumio[25329]: assert.ok(self.idling) Feb 17 09:36:18 music volumio[25329]: error: updateQueue error: null Feb 17 09:36:18 music sudo[25600]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:36:18 music sudo[25600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:18 music sudo[25600]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:18 music sudo[25602]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:36:18 music sudo[25602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:18 music sudo[25602]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:18 music sudo[25604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:36:18 music sudo[25604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:18 music sudo[25604]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:18 music volumio[25329]: info: Upmpdcli Daemon Started Feb 17 09:36:19 music volumio[25329]: info: go-librespot daemon successfully initialized Feb 17 09:36:19 music go-librespot[25526]: time="2026-02-17T09:36:19-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:19 music go-librespot[25526]: time="2026-02-17T09:36:19-05:00" level=debug msg="completed challenge" Feb 17 09:36:19 music go-librespot[25526]: time="2026-02-17T09:36:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:20 music go-librespot[25526]: time="2026-02-17T09:36:20-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:36:20 music go-librespot[25526]: time="2026-02-17T09:36:20-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:20 music go-librespot[25526]: time="2026-02-17T09:36:20-05:00" level=debug msg="completed challenge" Feb 17 09:36:21 music go-librespot[25526]: time="2026-02-17T09:36:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:21 music go-librespot[25526]: time="2026-02-17T09:36:21-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 17 09:36:21 music go-librespot[25526]: time="2026-02-17T09:36:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 09:36:21 music go-librespot[25526]: time="2026-02-17T09:36:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 09:36:21 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:21 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:22 music volumio[25329]: info: Initializing connection to go-librespot Websocket Feb 17 09:36:22 music volumio[25329]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:36:23 music volumio[25329]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:36:23 music volumio[25329]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:23 music volumio[25329]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:25 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 09:36:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:25 music volumio[25329]: info: Initializing connection to go-librespot Websocket Feb 17 09:36:25 music volumio[25329]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:36:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:25 music go-librespot[25609]: go-librespot daemon starting... Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="app state loaded" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=info msg="zeroconf server listening on port 40523" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="obtained new client token: AAA4Ktufc75TKaULZL/PtlEZs3/fgAxdrhh5CCrvzA6TF+fc1ntn38PgPnQM7+DRpTy1E8GnBjCBWmGHq4gOhM7PEYyuUBbt9reDe3Q2CONN81PDsrEZLhahUYwzz792WDOtEDr7j10SDUrCO04O13iC49bN64gLdzhGYbf1arinMcHxbx7QnSesRoM2Q33iEb+bvUYMcF+PNa6H2Am0XYwxuIlwdl4riwXEbTWtc1nvzEqHwHD3++o=" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=debug msg="completed challenge" Feb 17 09:36:25 music go-librespot[25610]: time="2026-02-17T09:36:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:26 music go-librespot[25610]: time="2026-02-17T09:36:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:26 music go-librespot[25610]: time="2026-02-17T09:36:26-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:26 music go-librespot[25610]: time="2026-02-17T09:36:26-05:00" level=debug msg="completed challenge" Feb 17 09:36:26 music go-librespot[25610]: time="2026-02-17T09:36:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:36:26 music volumio[25329]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:36:26 music volumio[25329]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=debug msg="completed challenge" Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:27 music volumio[25329]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:36:27 music volumio[25329]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:36:27 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:27 music volumio[25329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:27 music volumio[25329]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:36:27 music volumio[25329]: info: MyVolumio login type: Token Feb 17 09:36:27 music volumio[25329]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:36:27 music volumio[25329]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=debug msg="completed challenge" Feb 17 09:36:27 music go-librespot[25610]: time="2026-02-17T09:36:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:28 music volumio[25329]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:36:28 music volumio[25329]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:36:28 music volumio[25329]: info: Streaming services startup Feb 17 09:36:28 music volumio[25329]: info: Starting Streaming Daemon Feb 17 09:36:28 music go-librespot[25610]: time="2026-02-17T09:36:28-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:36:28 music sudo[25634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:36:28 music sudo[25634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:28 music volumio[25329]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:36:28 music sudo[25634]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:28 music volumio[25329]: info: Initializing connection to go-librespot Websocket Feb 17 09:36:28 music volumio[25329]: error: Cannot start Volumio Streaming Daemon Feb 17 09:36:28 music volumio[25329]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 09:36:28 music volumio[25329]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 09:36:28 music go-librespot[25610]: time="2026-02-17T09:36:28-05:00" level=debug msg="new websocket client" Feb 17 09:36:28 music volumio[25329]: info: Connection to go-librespot Websocket established Feb 17 09:36:28 music go-librespot[25610]: time="2026-02-17T09:36:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:45492->104.199.241.202:443: read: connection reset by peer" Feb 17 09:36:29 music volumio[25329]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 17 09:36:29 music go-librespot[25610]: time="2026-02-17T09:36:29-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 17 09:36:29 music go-librespot[25610]: time="2026-02-17T09:36:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:33630->104.199.65.9:80: read: connection reset by peer" Feb 17 09:36:29 music go-librespot[25610]: time="2026-02-17T09:36:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:33630->104.199.65.9:80: read: connection reset by peer" Feb 17 09:36:29 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:29 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:29 music volumio[25329]: info: Connection to go-librespot Websocket closed Feb 17 09:36:29 music volumio[25329]: info: MyVolumio token set successfully Feb 17 09:36:29 music volumio[25329]: info: MYVOLUMIO: Adding device Feb 17 09:36:29 music volumio[25329]: info: MYVOLUMIO: Evaluating Server Feb 17 09:36:29 music volumio[25329]: info: MyVolumio status changed Feb 17 09:36:29 music volumio[25329]: info: Streaming services startup Feb 17 09:36:29 music volumio[25329]: info: Starting Streaming Daemon Feb 17 09:36:29 music volumio[25329]: info: Removing browser output: myVolumio user plan is not superstar Feb 17 09:36:29 music volumio[25329]: info: Removing audio output: Feb 17 09:36:29 music volumio[25329]: info: Stoppping Tunnel 1 Feb 17 09:36:29 music sudo[25661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:36:29 music sudo[25661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:29 music sudo[25663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 17 09:36:29 music sudo[25663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:30 music 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 17 09:36:30 music 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 17 09:36:30 music sudo[25661]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:30 music volumio[25329]: error: Cannot start Volumio Streaming Daemon Feb 17 09:36:30 music volumio[25329]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 09:36:30 music volumio[25329]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 09:36:30 music 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 17 09:36:30 music 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 17 09:36:30 music 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 17 09:36:30 music 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 17 09:36:30 music 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 17 09:36:30 music 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 17 09:36:30 music sudo[25663]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:30 music volumio[25329]: info: Remote SSH Stopped Feb 17 09:36:31 music volumio[25329]: info: Getting Spotify volume Feb 17 09:36:31 music volumio[25329]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:36:31 music volumio[25329]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:36:31 music volumio[25329]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:36:31 music volumio[25329]: errno: -111, Feb 17 09:36:31 music volumio[25329]: code: 'ECONNREFUSED', Feb 17 09:36:31 music volumio[25329]: syscall: 'connect', Feb 17 09:36:31 music volumio[25329]: address: '127.0.0.1', Feb 17 09:36:31 music volumio[25329]: port: 9879, Feb 17 09:36:31 music volumio[25329]: response: undefined Feb 17 09:36:31 music volumio[25329]: } Feb 17 09:36:31 music volumio[25329]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:36:32 music sudo[25680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:35' Feb 17 09:36:32 music sudo[25680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:32 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 09:36:32 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:32 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:32 music go-librespot[25682]: go-librespot daemon starting... Feb 17 09:36:32 music sudo[25680]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:32 music go-librespot[25683]: time="2026-02-17T09:36:32-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:32 music go-librespot[25683]: time="2026-02-17T09:36:32-05:00" level=debug msg="app state loaded" Feb 17 09:36:32 music go-librespot[25683]: time="2026-02-17T09:36:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=info msg="zeroconf server listening on port 35683" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="obtained new client token: AAADs4lHGIpczxG64rHoGANfAdb0WG9ZbRtJHZRbmPosF8+MxuH6aUF7jZfYfi/ucKlefG6sXyJIj1bC9TCXEkPJMoyRrMZKa3EbFwvbhBpOaCxsg52RXHbdoROCUiJFWb0t+DEk2Oyyrn/6x1XXjcubMTwfi6ujf6T80RFEnpcrJiQ3NESoIzRcVqZ8wUw5f3Qx7CXm0bN/q7xrOQ5anu4V/FU4Vbgr6hC9WXsKOfPZOuH3U5/q1QE=" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=debug msg="completed challenge" Feb 17 09:36:33 music go-librespot[25683]: time="2026-02-17T09:36:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:33 music volumio-remote-updater[11935]: [2026-02-17 09:36:33] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:36:33 music volumio-remote-updater[11935]: [2026-02-17 09:36:33] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:36:33 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:33 music volumio5-onboarding[32661]: time=2026-02-17T09:36:33.696-05:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 17 09:36:33 music volumio5-onboarding[32661]: time=2026-02-17T09:36:33.699-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:36:33 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:36:33 music systemd[1]: volumio.service: Consumed 27.783s CPU time. Feb 17 09:36:33 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:36:33 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:36:34 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3245. Feb 17 09:36:34 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:36:34 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:36:34 music systemd[1]: volumio.service: Consumed 27.783s CPU time. Feb 17 09:36:34 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:36:34 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:36:34 music go-librespot[25683]: time="2026-02-17T09:36:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:34 music go-librespot[25683]: time="2026-02-17T09:36:34-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:34 music go-librespot[25683]: time="2026-02-17T09:36:34-05:00" level=debug msg="completed challenge" Feb 17 09:36:34 music go-librespot[25683]: time="2026-02-17T09:36:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:34 music volumio5-onboarding[32661]: time=2026-02-17T09:36:34.701-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:36:34 music go-librespot[25683]: time="2026-02-17T09:36:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:35 music go-librespot[25683]: time="2026-02-17T09:36:35-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:35 music go-librespot[25683]: time="2026-02-17T09:36:35-05:00" level=debug msg="completed challenge" Feb 17 09:36:35 music go-librespot[25683]: time="2026-02-17T09:36:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:35 music go-librespot[25683]: time="2026-02-17T09:36:35-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:36:35 music go-librespot[25683]: time="2026-02-17T09:36:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:33464->104.199.241.202:4070: read: connection reset by peer" Feb 17 09:36:36 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:36 music volumio[25708]: info: ----- Volumio3 ---- Feb 17 09:36:36 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:36 music volumio[25708]: info: ----- System startup ---- Feb 17 09:36:36 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:36 music go-librespot[25683]: time="2026-02-17T09:36:36-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 17 09:36:36 music volumio[25708]: info: MYVOLUMIO Environment detected Feb 17 09:36:36 music volumio[25708]: info: Plugin folders cleanup Feb 17 09:36:36 music volumio[25708]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:36:36 music volumio[25708]: info: Scanning category audio_interface Feb 17 09:36:36 music volumio[25708]: info: Scanning category miscellanea Feb 17 09:36:36 music volumio[25708]: info: Scanning category music_service Feb 17 09:36:36 music volumio[25708]: info: Scanning category plugins.json Feb 17 09:36:36 music volumio[25708]: info: Scanning category system_controller Feb 17 09:36:36 music volumio[25708]: info: Scanning category user_interface Feb 17 09:36:36 music volumio[25708]: info: Scanning into folder /data/plugins/ Feb 17 09:36:36 music volumio[25708]: info: Scanning category music_service Feb 17 09:36:36 music volumio[25708]: info: Plugin folders cleanup completed Feb 17 09:36:36 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:36 music volumio[25708]: info: ----- Core plugins startup ---- Feb 17 09:36:36 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:36 music volumio[25708]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:36:36 music volumio[25708]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:36:36 music volumio[25708]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:36:36 music volumio[25708]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:36:36 music volumio[25708]: info: Loading plugins from folder /data/plugins/ Feb 17 09:36:36 music volumio[25708]: info: Loading plugin "system"... Feb 17 09:36:36 music volumio[25708]: info: Loading plugin "appearance"... Feb 17 09:36:37 music go-librespot[25683]: time="2026-02-17T09:36:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:44662->104.199.65.9:443: read: connection reset by peer" Feb 17 09:36:37 music go-librespot[25683]: time="2026-02-17T09:36:37-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "network"... Feb 17 09:36:38 music volumio[25708]: info: Refreshing Cached IP Addresses Feb 17 09:36:38 music sudo[25736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:36:38 music sudo[25736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:38 music sudo[25738]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:36:38 music sudo[25738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:38 music sudo[25736]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "services"... Feb 17 09:36:38 music sudo[25738]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "volumio5onboarding"... Feb 17 09:36:38 music go-librespot[25683]: time="2026-02-17T09:36:38-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:38 music go-librespot[25683]: time="2026-02-17T09:36:38-05:00" level=debug msg="completed challenge" Feb 17 09:36:38 music sudo[25746]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:36:38 music sudo[25746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "alsa_controller"... Feb 17 09:36:38 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "wizard"... Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "networkfs"... Feb 17 09:36:38 music volumio[25708]: info: Starting Udev Watcher for removable devices Feb 17 09:36:38 music go-librespot[25683]: time="2026-02-17T09:36:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:38 music go-librespot[25683]: time="2026-02-17T09:36:38-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:38 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:38 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:38 music volumio[25708]: info: Ignoring mount for partition: boot Feb 17 09:36:38 music volumio[25708]: info: Ignoring mount for partition: volumio Feb 17 09:36:38 music volumio[25708]: info: Ignoring mount for partition: volumio_data Feb 17 09:36:38 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "upnp"... Feb 17 09:36:38 music volumio[25708]: info: [1771338998287] Starting Upmpd Daemon Feb 17 09:36:38 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "my_music"... Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "mpd"... Feb 17 09:36:38 music volumio[25708]: info: Loading plugin "upnp_browser"... Feb 17 09:36:38 music volumio-remote-updater[11935]: [2026-02-17 09:36:38] [connect] Successful connection Feb 17 09:36:38 music sudo[25746]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:40 music volumio[25708]: info: Starting UPNP Browser Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "alarm-clock"... Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "airplay_emulation"... Feb 17 09:36:40 music volumio[25708]: info: Starting Shairport Sync Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "last_100"... Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "webradio"... Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "i2s_dacs"... Feb 17 09:36:40 music volumio[25708]: info: I2S DAC not set, start Auto-detection Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "volumiodiscovery"... Feb 17 09:36:40 music volumio[25708]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:40 music volumio[25708]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:40 music volumio[25708]: *** WARNING *** For more information see Feb 17 09:36:40 music volumio[25708]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:40 music volumio[25708]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:40 music volumio[25708]: *** WARNING *** For more information see Feb 17 09:36:40 music node[25708]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:40 music node[25708]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:40 music node[25708]: *** WARNING *** For more information see Feb 17 09:36:40 music node[25708]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:36:40 music node[25708]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:36:40 music node[25708]: *** WARNING *** For more information see Feb 17 09:36:40 music volumio[25708]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:36:40 music volumio[25708]: info: Discovery: Started advertising with name: music Feb 17 09:36:40 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:36:40 music volumio[25708]: info: Loading plugin "spop"... Feb 17 09:36:41 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 09:36:41 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:41 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:41 music go-librespot[25772]: go-librespot daemon starting... Feb 17 09:36:41 music volumio[25708]: info: Loading plugin "outputs"... Feb 17 09:36:41 music volumio[25708]: info: Loading plugin "albumart"... Feb 17 09:36:41 music go-librespot[25773]: time="2026-02-17T09:36:41-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:41 music go-librespot[25773]: time="2026-02-17T09:36:41-05:00" level=debug msg="app state loaded" Feb 17 09:36:41 music go-librespot[25773]: time="2026-02-17T09:36:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:41 music volumio[25708]: info: Plugin example_plugin is not enabled Feb 17 09:36:41 music volumio[25708]: info: Loading plugin "inputs"... Feb 17 09:36:41 music volumio[25708]: info: Loading plugin "updater_comm"... Feb 17 09:36:41 music volumio[25708]: info: Plugin mpdemulation is not enabled Feb 17 09:36:41 music volumio[25708]: info: Loading plugin "rest_api"... Feb 17 09:36:41 music volumio[25708]: info: Loading plugin "websocket"... Feb 17 09:36:41 music volumio[25708]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:36:41 music volumio[25708]: info: Loading i18n strings for locale en Feb 17 09:36:41 music volumio[25708]: Updating browse sources language Feb 17 09:36:41 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=info msg="zeroconf server listening on port 35815" Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::initPlayerControls Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:36:42 music volumio[25708]: Express server listening on port 3000 Feb 17 09:36:42 music volumio[25708]: [Metrics] WebUI: 6s 569.82ms Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::resetVolumioState Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::getcurrentVolume Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="obtained new client token: AAAE+k8fz6/BA3lSRYs67Cw+3/I8FIt1JqxiT68KmgonyXoIjZebpccau/wgbmHRn3kv4cjjI80eR8ke5P2LNQrqQXyusSVtN4eOmGUDXflXH+3pzfP9f+gc84OJ8Jo3LdQbqE1+VmDkcDxcPefEisEJs1bqiUbo3q2UoUa+kXdK8hN3ubhhirtU2BwgeodEgjThasl+t1chO0YxFspbuj9CTdwUMKt6ClIX7Nyn0B4XyrfREcaf" Feb 17 09:36:42 music volumio[25708]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:42 music volumio[25781]: Forking 3 albumart workers Feb 17 09:36:42 music volumio[25708]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 17 09:36:42 music volumio[25708]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::pushState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="completed challenge" Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::updateTrackBlock Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrackBlock Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:42 music volumio[25708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 17 09:36:42 music volumio[25708]: info: Reloading queue from file Feb 17 09:36:42 music volumio[25708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 17 09:36:42 music volumio[25708]: info: Received Get System Info Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:36:42 music volumio[25708]: info: Discovery: Getting this device information Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:36:42 music volumio[25708]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::pushState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::setRandom null Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::pushState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:42 music volumio[25708]: info: Setting Device type: Raspberry PI Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 17 09:36:42 music volumio-remote-updater[11935]: [2026-02-17 09:36:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771338998 101 Feb 17 09:36:42 music volumio[25708]: 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: 4 Feb 17 09:36:42 music volumio[25708]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:36:42 music volumio[25708]: info: CoreStateMachine::pushState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioPushState Feb 17 09:36:42 music volumio[25708]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:36:42 music volumio[25708]: info: Discovery: Found device music Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music volumio[25708]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:36:42 music volumio[25708]: info: Discovery: Found device music Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:42 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:42 music volumio[25708]: info: Completed loading Core Plugins Feb 17 09:36:42 music volumio[25708]: info: Preparing to generate the ALSA configuration file Feb 17 09:36:42 music volumio[25708]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:36:42 music volumio[25708]: info: Output device has changed, restarting MPD Feb 17 09:36:42 music volumio[25708]: info: Output device has changed, restarting Shairport Sync Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:36:42 music volumio[25708]: info: ___________ START PLUGINS ___________ Feb 17 09:36:42 music sudo[25838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:36:42 music sudo[25838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:42 music sudo[25838]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:42 music sudo[25841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:36:42 music sudo[25841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:42 music volumio[25708]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:36:42 music volumio[25708]: info: Creating MPD Configuration file Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:42 music volumio[25708]: info: [1771339002923] CoreMusicLibrary::Adding element Media Servers Feb 17 09:36:42 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:42 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:36:42 music sudo[25850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:36:42 music sudo[25850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:42 music sudo[25848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 17 09:36:42 music sudo[25848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:42 music sudo[25852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:36:42 music sudo[25852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:42 music go-librespot[25773]: time="2026-02-17T09:36:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:42 music volumio[25708]: info: UPNP Browser: Client initialized successfully Feb 17 09:36:43 music sudo[25850]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:43 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:36:43 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:36:43 music systemd[1]: mpd.service: Consumed 4.182s CPU time. Feb 17 09:36:43 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:36:43 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:36:43 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=debug msg="completed challenge" Feb 17 09:36:43 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:36:43 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:36:43 music volumio[25708]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:43 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:36:43 music sudo[25848]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:43 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:36:43 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:36:43 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:36:43 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:36:43 music volumio[25708]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:43 music volumio[25708]: info: [1771339003195] CoreMusicLibrary::Adding element Last_100 Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:43 music volumio[25708]: info: [1771339003200] CoreMusicLibrary::Adding element Webradio Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:43 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:36:43 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:36:43 music volumio[25708]: info: Initializing BBC Radios Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:43 music volumio[25708]: info: Creating Spotify config file Feb 17 09:36:43 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:43 music sudo[25867]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:36:43 music sudo[25867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:36:43 music sudo[25867]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=debug msg="completed challenge" Feb 17 09:36:43 music go-librespot[25773]: time="2026-02-17T09:36:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:44 music volumio[25708]: info: Volumio Calling Home Feb 17 09:36:44 music volumio[25800]: Starting albumart workers Feb 17 09:36:44 music volumio[25801]: Starting albumart workers Feb 17 09:36:44 music volumio[25799]: Starting albumart workers Feb 17 09:36:44 music go-librespot[25773]: time="2026-02-17T09:36:44-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:36:44 music go-librespot[25773]: time="2026-02-17T09:36:44-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:44 music go-librespot[25773]: time="2026-02-17T09:36:44-05:00" level=debug msg="completed challenge" Feb 17 09:36:44 music go-librespot[25773]: time="2026-02-17T09:36:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:44 music volumio[25708]: info: MPD Permissions set Feb 17 09:36:44 music volumio[25708]: info: MPD Permissions set Feb 17 09:36:44 music volumio[25708]: info: Volumio called home Feb 17 09:36:44 music volumio[25708]: info: Spotify config file written Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:45 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:45 music sudo[25887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:36:45 music sudo[25887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:45 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 09:36:45 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 09:36:45 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:45 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:45 music go-librespot[25895]: go-librespot daemon starting... Feb 17 09:36:45 music sudo[25887]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=debug msg="app state loaded" Feb 17 09:36:45 music volumio[25708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:36:45 music volumio[25708]: info: No need to fix Spotify hosts Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=info msg="zeroconf server listening on port 35333" Feb 17 09:36:45 music volumio[25708]: info: Listing playlists Feb 17 09:36:45 music volumio[25708]: info: Listing playlists Feb 17 09:36:45 music volumio[25708]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 17 09:36:45 music volumio[25708]: info: Starting Shairport Sync Feb 17 09:36:45 music volumio[25708]: info: Starting Shairport Sync Feb 17 09:36:45 music volumio[25708]: info: Starting Shairport Sync Feb 17 09:36:45 music sudo[25928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:36:45 music sudo[25928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:45 music volumio[25708]: info: New Spotify access tokenBQDkCrUBzm... Feb 17 09:36:45 music volumio[25708]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:36:45 music sudo[25933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:36:45 music sudo[25933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=debug msg="obtained new client token: AACkYn1WmLe1NuyPR9LS0+09YJezA2915Onw8QMOFMX4xXPOmO/+GJZdiHkBdqDv+h8fc//9u1m2VfXoPRC+wToc5XtpTZO3VUGCusmXq1uXZp045fw9HeBjqRuVCrAH5s008hzoC8IU1k16v+9D/TM0lAl8UVEBquyFg6HiXFtjLzhyDexvAEJWeWsCesknHwFsQ0RpF9lE0UXxuVgencjgWtfRy42oIUTPp8RYq3EfH2l7Xuyt8So=" Feb 17 09:36:45 music sudo[25931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:36:45 music sudo[25931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::volumioGetVisibleSources Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:45 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::volumioGetQueue Feb 17 09:36:45 music volumio[25708]: info: CoreStateMachine::getQueue Feb 17 09:36:45 music go-librespot[25896]: time="2026-02-17T09:36:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:45 music volumio[25708]: info: CorePlayQueue::getQueue Feb 17 09:36:45 music volumio[25708]: info: Listing playlists Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 17 09:36:45 music volumio[25708]: info: Received Get System Info Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:36:45 music volumio[25708]: info: Discovery: Getting this device information Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:45 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:36:45 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:45 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:45 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:36:45 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:36:45 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:36:45 music systemd[1]: shairport-sync.service: Consumed 1.870s CPU time. Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=debug msg="completed challenge" Feb 17 09:36:46 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:36:46 music sudo[25928]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:46 music sudo[25931]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:46 music sudo[25933]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:46 music volumio[25708]: info: Shairport-Sync Started Feb 17 09:36:46 music volumio[25708]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:36:46 music volumio[25708]: info: Shairport-Sync Started Feb 17 09:36:46 music volumio[25708]: info: Shairport-Sync Started Feb 17 09:36:46 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:46 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:46 music volumio[25708]: SPOTIFY: User informations: {"country":"US","display_name":"Clipinger Sporing Law","email":"maryalyce@cliplaw.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mltxw4dg22kb3gk2jynmhfuwt4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31mltxw4dg22kb3gk2jynmhfuwt4","id":"31mltxw4dg22kb3gk2jynmhfuwt4","images":[],"product":"premium","type":"user","uri":"spotify:user:31mltxw4dg22kb3gk2jynmhfuwt4"} Feb 17 09:36:46 music volumio[25708]: info: Spotify Successfully logged in Feb 17 09:36:46 music volumio[25708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:36:46 music volumio[25708]: info: [1771339006309] CoreMusicLibrary::Adding element Spotify Feb 17 09:36:46 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:36:46 music volumio[25708]: Cannot find translation for source Spotify Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=debug msg="completed challenge" Feb 17 09:36:46 music go-librespot[25896]: time="2026-02-17T09:36:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:47 music go-librespot[25896]: time="2026-02-17T09:36:47-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:47 music go-librespot[25896]: time="2026-02-17T09:36:47-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:47 music go-librespot[25896]: time="2026-02-17T09:36:47-05:00" level=debug msg="completed challenge" Feb 17 09:36:47 music go-librespot[25896]: time="2026-02-17T09:36:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:47 music mpd[25882]: 2026-02-17T09:36:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:36:47 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:36:47 music sudo[25841]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:47 music sudo[25852]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:47 music volumio[25708]: info: Completed starting Core Plugins Feb 17 09:36:47 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:47 music volumio[25708]: info: ----- MyVolumio plugins startup ---- Feb 17 09:36:47 music volumio[25708]: info: ------------------------------------------- Feb 17 09:36:47 music volumio[25708]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:36:47 music volumio[25708]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:36:47 music volumio[25708]: assert.ok(self.idling) Feb 17 09:36:47 music volumio[25708]: error: The expression evaluated to a falsy value: Feb 17 09:36:47 music volumio[25708]: assert.ok(self.idling) Feb 17 09:36:47 music volumio[25708]: error: updateQueue error: null Feb 17 09:36:47 music volumio[25708]: info: MPD running with PID25882 Feb 17 09:36:47 music volumio[25708]: ,establishing connection Feb 17 09:36:47 music volumio[25708]: error: updateQueue error: null Feb 17 09:36:48 music go-librespot[25896]: time="2026-02-17T09:36:48-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:36:48 music go-librespot[25896]: time="2026-02-17T09:36:48-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:48 music go-librespot[25896]: time="2026-02-17T09:36:48-05:00" level=debug msg="completed challenge" Feb 17 09:36:48 music go-librespot[25896]: time="2026-02-17T09:36:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:48 music sudo[25971]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:36:48 music sudo[25971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:48 music sudo[25971]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:48 music sudo[25973]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:36:48 music sudo[25973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:48 music sudo[25973]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:48 music sudo[25976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:36:48 music sudo[25976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:48 music sudo[25976]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:48 music volumio[25708]: info: Upmpdcli Daemon Started Feb 17 09:36:48 music volumio[25708]: info: go-librespot daemon successfully initialized Feb 17 09:36:48 music go-librespot[25896]: time="2026-02-17T09:36:48-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:36:49 music go-librespot[25896]: time="2026-02-17T09:36:49-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:49 music go-librespot[25896]: time="2026-02-17T09:36:49-05:00" level=debug msg="completed challenge" Feb 17 09:36:49 music go-librespot[25896]: time="2026-02-17T09:36:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:49 music go-librespot[25896]: time="2026-02-17T09:36:49-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:36:50 music go-librespot[25896]: time="2026-02-17T09:36:50-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:50 music go-librespot[25896]: time="2026-02-17T09:36:50-05:00" level=debug msg="completed challenge" Feb 17 09:36:50 music go-librespot[25896]: time="2026-02-17T09:36:50-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:50 music go-librespot[25896]: time="2026-02-17T09:36:50-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:50 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:50 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:51 music volumio[25708]: info: Initializing connection to go-librespot Websocket Feb 17 09:36:51 music volumio[25708]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:36:52 music volumio[25708]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:36:53 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 09:36:53 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:53 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:36:53 music go-librespot[25979]: go-librespot daemon starting... Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="app state loaded" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=info msg="zeroconf server listening on port 40713" Feb 17 09:36:53 music volumio[25708]: info: CoreCommandRouter::volumioGetState Feb 17 09:36:53 music volumio[25708]: info: CorePlayQueue::getTrack 0 Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="obtained new client token: AADCan0VqMSjGtPbrxWqdBpi6lnyEoFti955y2sJ7lbXTPRsX/B+yxXkKc3ZSQrhqmNU1baJbfgY5G+HA7s8jn5wlNAhN8cwc9HwD/ZZQv63PRj1YgSZhlornxzq65JIXjpZ1OeIqrW9huMlI3RnMJVHLqxK728bRFEcz61QyRsX4EAyj30m9T8lbIwYPNv1sOEqfvBJDvqdrf13z9seKciajl5J8XLJ16ZTXjim/N0uf1SVGibCPtU=" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:53 music go-librespot[25980]: time="2026-02-17T09:36:53-05:00" level=debug msg="completed challenge" Feb 17 09:36:54 music go-librespot[25980]: time="2026-02-17T09:36:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:54 music go-librespot[25980]: time="2026-02-17T09:36:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:36:54 music go-librespot[25980]: time="2026-02-17T09:36:54-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:54 music go-librespot[25980]: time="2026-02-17T09:36:54-05:00" level=debug msg="completed challenge" Feb 17 09:36:54 music go-librespot[25980]: time="2026-02-17T09:36:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:54 music volumio[25708]: info: Initializing connection to go-librespot Websocket Feb 17 09:36:54 music go-librespot[25980]: time="2026-02-17T09:36:54-05:00" level=debug msg="new websocket client" Feb 17 09:36:54 music volumio[25708]: info: Connection to go-librespot Websocket established Feb 17 09:36:55 music go-librespot[25980]: time="2026-02-17T09:36:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:36:55 music go-librespot[25980]: time="2026-02-17T09:36:55-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:55 music go-librespot[25980]: time="2026-02-17T09:36:55-05:00" level=debug msg="completed challenge" Feb 17 09:36:55 music go-librespot[25980]: time="2026-02-17T09:36:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:36:55 music volumio[25708]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:36:55 music volumio[25708]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:36:55 music go-librespot[25980]: time="2026-02-17T09:36:55-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=debug msg="completed challenge" Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:36:56 music volumio[25708]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:36:56 music volumio[25708]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:36:56 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:56 music volumio[25708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:36:56 music volumio[25708]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:56 music go-librespot[25980]: time="2026-02-17T09:36:56-05:00" level=debug msg="completed challenge" Feb 17 09:36:56 music volumio[25708]: info: MyVolumio login type: Token Feb 17 09:36:56 music volumio[25708]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:36:56 music volumio[25708]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:36:57 music go-librespot[25980]: time="2026-02-17T09:36:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:57 music go-librespot[25980]: time="2026-02-17T09:36:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:36:57 music go-librespot[25980]: time="2026-02-17T09:36:57-05:00" level=debug msg="completed keyexchange" Feb 17 09:36:57 music go-librespot[25980]: time="2026-02-17T09:36:57-05:00" level=debug msg="completed challenge" Feb 17 09:36:57 music go-librespot[25980]: time="2026-02-17T09:36:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:57 music go-librespot[25980]: time="2026-02-17T09:36:57-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:36:57 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:57 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:36:57 music volumio[25708]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:36:57 music volumio[25708]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:36:57 music volumio[25708]: info: Streaming services startup Feb 17 09:36:57 music volumio[25708]: info: Starting Streaming Daemon Feb 17 09:36:57 music sudo[25990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:36:57 music sudo[25990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:57 music volumio[25708]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:36:57 music sudo[25990]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:57 music volumio[25708]: info: Getting Spotify volume Feb 17 09:36:58 music volumio[25708]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:36:58 music volumio[25708]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:36:58 music volumio[25708]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:36:58 music volumio[25708]: errno: -111, Feb 17 09:36:58 music volumio[25708]: code: 'ECONNREFUSED', Feb 17 09:36:58 music volumio[25708]: syscall: 'connect', Feb 17 09:36:58 music volumio[25708]: address: '127.0.0.1', Feb 17 09:36:58 music volumio[25708]: port: 9879, Feb 17 09:36:58 music volumio[25708]: response: undefined Feb 17 09:36:58 music volumio[25708]: } Feb 17 09:36:58 music volumio[25708]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:36:58 music sudo[26025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:35' Feb 17 09:36:58 music sudo[26025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:36:59 music sudo[26025]: pam_unix(sudo:session): session closed for user root Feb 17 09:36:59 music volumio-remote-updater[11935]: [2026-02-17 09:36:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:36:59 music volumio-remote-updater[11935]: [2026-02-17 09:36:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:36:59 music volumio5-onboarding[32661]: time=2026-02-17T09:36:59.166-05:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 17 09:36:59 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:36:59 music volumio5-onboarding[32661]: time=2026-02-17T09:36:59.173-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:36:59 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:36:59 music systemd[1]: volumio.service: Consumed 26.695s CPU time. Feb 17 09:36:59 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:36:59 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:36:59 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3246. Feb 17 09:36:59 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:36:59 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:36:59 music systemd[1]: volumio.service: Consumed 26.695s CPU time. Feb 17 09:36:59 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:36:59 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:37:00 music volumio5-onboarding[32661]: time=2026-02-17T09:37:00.175-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:37:01 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 09:37:01 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:01 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:01 music go-librespot[26053]: go-librespot daemon starting... Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="app state loaded" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=info msg="zeroconf server listening on port 34229" Feb 17 09:37:01 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:01 music volumio[26037]: info: ----- Volumio3 ---- Feb 17 09:37:01 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:01 music volumio[26037]: info: ----- System startup ---- Feb 17 09:37:01 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="obtained new client token: AABW1Ui3m9JNN/+pxpG8WvFowuvkMEbxJAuegsZu/IQQUSQrWL7G3AGnaNoHb/xH4GAvDgRhNyWQR6Q2n+GcOjR2WGdQe9ItgUczPpDDeyQZRT7MSj9c35p+7vqh629fEKBJ5qAAbwSwviznMJTy8H7N9Wjjj4T5eOdh+dBoqtf+s89r/7DJ+Zj5FZTNzAJva02Ua1/OppBQk9hy92gyUxsHBeTPy/oa9QG0JhrVN6caz6Q2Bw32V8E=" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" 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 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=debug msg="completed challenge" Feb 17 09:37:01 music go-librespot[26054]: time="2026-02-17T09:37:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:02 music volumio[26037]: info: MYVOLUMIO Environment detected Feb 17 09:37:02 music volumio[26037]: info: Plugin folders cleanup Feb 17 09:37:02 music volumio[26037]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:37:02 music volumio[26037]: info: Scanning category audio_interface Feb 17 09:37:02 music volumio[26037]: info: Scanning category miscellanea Feb 17 09:37:02 music volumio[26037]: info: Scanning category music_service Feb 17 09:37:02 music volumio[26037]: info: Scanning category plugins.json Feb 17 09:37:02 music volumio[26037]: info: Scanning category system_controller Feb 17 09:37:02 music volumio[26037]: info: Scanning category user_interface Feb 17 09:37:02 music volumio[26037]: info: Scanning into folder /data/plugins/ Feb 17 09:37:02 music volumio[26037]: info: Scanning category music_service Feb 17 09:37:02 music volumio[26037]: info: Plugin folders cleanup completed Feb 17 09:37:02 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:02 music volumio[26037]: info: ----- Core plugins startup ---- Feb 17 09:37:02 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:02 music volumio[26037]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:37:02 music volumio[26037]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:37:02 music volumio[26037]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:37:02 music volumio[26037]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:37:02 music volumio[26037]: info: Loading plugins from folder /data/plugins/ Feb 17 09:37:02 music volumio[26037]: info: Loading plugin "system"... Feb 17 09:37:02 music go-librespot[26054]: time="2026-02-17T09:37:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:37:02 music volumio[26037]: info: Loading plugin "appearance"... Feb 17 09:37:02 music go-librespot[26054]: time="2026-02-17T09:37:02-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:02 music go-librespot[26054]: time="2026-02-17T09:37:02-05:00" level=debug msg="completed challenge" Feb 17 09:37:02 music go-librespot[26054]: time="2026-02-17T09:37:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:03 music go-librespot[26054]: time="2026-02-17T09:37:03-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:37:03 music go-librespot[26054]: time="2026-02-17T09:37:03-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:03 music go-librespot[26054]: time="2026-02-17T09:37:03-05:00" level=debug msg="completed challenge" Feb 17 09:37:03 music go-librespot[26054]: time="2026-02-17T09:37:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "network"... Feb 17 09:37:03 music volumio[26037]: info: Refreshing Cached IP Addresses Feb 17 09:37:03 music sudo[26076]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:37:03 music sudo[26076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:03 music sudo[26078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:37:03 music sudo[26078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "services"... Feb 17 09:37:03 music sudo[26076]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "volumio5onboarding"... Feb 17 09:37:03 music sudo[26078]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:03 music sudo[26086]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "alsa_controller"... Feb 17 09:37:03 music sudo[26086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:03 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "wizard"... Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "networkfs"... Feb 17 09:37:03 music volumio[26037]: info: Starting Udev Watcher for removable devices Feb 17 09:37:03 music volumio[26037]: info: Ignoring mount for partition: boot Feb 17 09:37:03 music volumio[26037]: info: Ignoring mount for partition: volumio Feb 17 09:37:03 music volumio[26037]: info: Ignoring mount for partition: volumio_data Feb 17 09:37:03 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "upnp"... Feb 17 09:37:03 music volumio[26037]: info: [1771339023858] Starting Upmpd Daemon Feb 17 09:37:03 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "my_music"... Feb 17 09:37:03 music volumio[26037]: info: Loading plugin "mpd"... Feb 17 09:37:04 music go-librespot[26054]: time="2026-02-17T09:37:04-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:37:04 music volumio-remote-updater[11935]: [2026-02-17 09:37:04] [connect] Successful connection Feb 17 09:37:04 music volumio[26037]: info: Loading plugin "upnp_browser"... Feb 17 09:37:04 music sudo[26086]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:04 music go-librespot[26054]: time="2026-02-17T09:37:04-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:04 music go-librespot[26054]: time="2026-02-17T09:37:04-05:00" level=debug msg="completed challenge" Feb 17 09:37:04 music go-librespot[26054]: time="2026-02-17T09:37:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:05 music go-librespot[26054]: time="2026-02-17T09:37:05-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:37:05 music go-librespot[26054]: time="2026-02-17T09:37:05-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:05 music go-librespot[26054]: time="2026-02-17T09:37:05-05:00" level=debug msg="completed challenge" Feb 17 09:37:05 music go-librespot[26054]: time="2026-02-17T09:37:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:05 music volumio[26037]: info: Starting UPNP Browser Feb 17 09:37:05 music volumio[26037]: info: Loading plugin "alarm-clock"... Feb 17 09:37:05 music volumio[26037]: info: Loading plugin "airplay_emulation"... Feb 17 09:37:05 music volumio[26037]: info: Starting Shairport Sync Feb 17 09:37:05 music volumio[26037]: info: Loading plugin "last_100"... Feb 17 09:37:05 music volumio[26037]: info: Loading plugin "webradio"... Feb 17 09:37:06 music volumio[26037]: info: Loading plugin "i2s_dacs"... Feb 17 09:37:06 music volumio[26037]: info: I2S DAC not set, start Auto-detection Feb 17 09:37:06 music go-librespot[26054]: time="2026-02-17T09:37:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:06 music volumio[26037]: info: Loading plugin "volumiodiscovery"... Feb 17 09:37:06 music volumio[26037]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:06 music volumio[26037]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:06 music volumio[26037]: *** WARNING *** For more information see Feb 17 09:37:06 music volumio[26037]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:06 music volumio[26037]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:06 music volumio[26037]: *** WARNING *** For more information see Feb 17 09:37:06 music node[26037]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:06 music node[26037]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:06 music node[26037]: *** WARNING *** For more information see Feb 17 09:37:06 music node[26037]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:06 music node[26037]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:06 music node[26037]: *** WARNING *** For more information see Feb 17 09:37:06 music volumio[26037]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:37:06 music volumio[26037]: info: Discovery: Started advertising with name: music Feb 17 09:37:06 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:37:06 music volumio[26037]: info: Loading plugin "spop"... Feb 17 09:37:06 music go-librespot[26054]: time="2026-02-17T09:37:06-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:06 music go-librespot[26054]: time="2026-02-17T09:37:06-05:00" level=debug msg="completed challenge" Feb 17 09:37:06 music go-librespot[26054]: time="2026-02-17T09:37:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:06 music go-librespot[26054]: time="2026-02-17T09:37:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:06 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:06 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:37:07 music volumio[26037]: info: Loading plugin "outputs"... Feb 17 09:37:07 music volumio[26037]: info: Loading plugin "albumart"... Feb 17 09:37:07 music volumio[26037]: info: Plugin example_plugin is not enabled Feb 17 09:37:07 music volumio[26037]: info: Loading plugin "inputs"... Feb 17 09:37:07 music volumio[26037]: info: Loading plugin "updater_comm"... Feb 17 09:37:07 music volumio[26037]: info: Plugin mpdemulation is not enabled Feb 17 09:37:07 music volumio[26037]: info: Loading plugin "rest_api"... Feb 17 09:37:07 music volumio[26037]: info: Loading plugin "websocket"... Feb 17 09:37:07 music volumio[26037]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:37:07 music volumio[26037]: info: Loading i18n strings for locale en Feb 17 09:37:07 music volumio[26037]: Updating browse sources language Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::initPlayerControls Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:37:07 music volumio[26037]: Express server listening on port 3000 Feb 17 09:37:07 music volumio[26037]: [Metrics] WebUI: 6s 588.01ms Feb 17 09:37:07 music volumio[26037]: info: CoreStateMachine::resetVolumioState Feb 17 09:37:07 music volumio[26037]: info: CoreStateMachine::getcurrentVolume Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:07 music volumio[26037]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:37:07 music volumio[26037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 09:37:07 music volumio[26111]: Forking 3 albumart workers Feb 17 09:37:07 music volumio[26037]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:37:07 music volumio[26037]: info: CoreStateMachine::pushState Feb 17 09:37:07 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:07 music volumio[26037]: info: CoreStateMachine::updateTrackBlock Feb 17 09:37:07 music volumio[26037]: info: CorePlayQueue::getTrackBlock Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:37:07 music volumio[26037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 09:37:07 music volumio[26037]: info: Received Get System Info Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:37:07 music volumio[26037]: info: Discovery: Getting this device information Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:07 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:37:07 music volumio[26037]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Feb 17 09:37:07 music volumio[26037]: info: Reloading queue from file Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 17 09:37:07 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 17 09:37:08 music volumio[26037]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 17 09:37:08 music volumio[26037]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:37:08 music volumio[26037]: info: CoreStateMachine::pushState Feb 17 09:37:08 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:08 music volumio[26037]: info: CoreStateMachine::setRandom null Feb 17 09:37:08 music volumio[26037]: info: CoreStateMachine::pushState Feb 17 09:37:08 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:08 music volumio[26037]: info: Setting Device type: Raspberry PI Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:08 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:08 music volumio-remote-updater[11935]: [2026-02-17 09:37:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771339024 101 Feb 17 09:37:08 music volumio[26037]: 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: 4 Feb 17 09:37:08 music volumio[26037]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:37:08 music volumio[26037]: info: CoreStateMachine::pushState Feb 17 09:37:08 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:08 music volumio[26037]: info: Listing playlists Feb 17 09:37:08 music volumio[26037]: info: Listing playlists Feb 17 09:37:08 music volumio[26037]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:37:08 music volumio[26037]: info: Discovery: Found device music Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:08 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:08 music volumio[26037]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:37:08 music volumio[26037]: info: Discovery: Found device music Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:08 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:08 music volumio[26037]: info: Completed loading Core Plugins Feb 17 09:37:08 music volumio[26037]: info: Preparing to generate the ALSA configuration file Feb 17 09:37:08 music volumio[26037]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:37:08 music volumio[26037]: info: Output device has changed, restarting MPD Feb 17 09:37:08 music volumio[26037]: info: Output device has changed, restarting Shairport Sync Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:08 music sudo[26166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:37:08 music sudo[26166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:08 music volumio[26037]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:37:08 music volumio[26037]: info: ___________ START PLUGINS ___________ Feb 17 09:37:08 music sudo[26166]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:08 music sudo[26168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:37:08 music sudo[26168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:08 music volumio[26037]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:37:08 music volumio[26037]: info: Creating MPD Configuration file Feb 17 09:37:08 music sudo[26176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:08 music volumio[26037]: info: [1771339028452] CoreMusicLibrary::Adding element Media Servers Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:08 music sudo[26176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:08 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:37:08 music volumio[26037]: info: UPNP Browser: Client initialized successfully Feb 17 09:37:08 music sudo[26180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:37:08 music sudo[26180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:08 music sudo[26180]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:08 music sudo[26176]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:08 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:37:08 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:37:08 music systemd[1]: mpd.service: Consumed 4.181s CPU time. Feb 17 09:37:08 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:37:08 music sudo[26179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:37:08 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:37:08 music sudo[26179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:08 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:37:08 music volumio[26037]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:08 music volumio[26037]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:37:08 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:08 music volumio[26037]: info: [1771339028635] CoreMusicLibrary::Adding element Last_100 Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:08 music volumio[26037]: info: [1771339028642] CoreMusicLibrary::Adding element Webradio Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:08 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:37:08 music volumio[26037]: info: Initializing BBC Radios Feb 17 09:37:08 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:37:08 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:37:08 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:37:08 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:37:08 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:37:08 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:37:08 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:08 music volumio[26037]: info: Creating Spotify config file Feb 17 09:37:08 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:09 music sudo[26203]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:37:09 music sudo[26203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:37:09 music sudo[26203]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:09 music volumio[26037]: info: Volumio Calling Home Feb 17 09:37:09 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 09:37:09 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:09 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:09 music go-librespot[26214]: go-librespot daemon starting... Feb 17 09:37:09 music go-librespot[26215]: time="2026-02-17T09:37:09-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:09 music volumio[26127]: Starting albumart workers Feb 17 09:37:09 music volumio[26037]: info: MPD Permissions set Feb 17 09:37:09 music volumio[26037]: info: MPD Permissions set Feb 17 09:37:09 music volumio[26037]: info: Volumio called home Feb 17 09:37:09 music volumio[26037]: info: Spotify config file written Feb 17 09:37:09 music volumio[26130]: Starting albumart workers Feb 17 09:37:10 music volumio[26128]: Starting albumart workers Feb 17 09:37:10 music sudo[26223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:37:10 music sudo[26223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:10 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 09:37:10 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 09:37:10 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:10 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:10 music go-librespot[26225]: go-librespot daemon starting... Feb 17 09:37:10 music sudo[26223]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=debug msg="app state loaded" Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:10 music volumio[26037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=info msg="zeroconf server listening on port 33539" Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:10 music volumio[26037]: info: No need to fix Spotify hosts Feb 17 09:37:10 music go-librespot[26226]: time="2026-02-17T09:37:10-05:00" level=debug msg="obtained new client token: AADRNbUYezhufCOfTtzp2dPPuUoTPGIr3y693i8xzr0OcjvJzV4IjgA0y0T0vByayEeEzCc/hI/CwOcuYVnVUuPUk6tOvdnBcqH8S2QaABP27wMoYr6hPElKcjMAQouf/QJPrb6UA8M5g2clDxkKUrE9/R9n0JIeNOOvX5v7BzY4ui20iy0IaHDvLxrumj3wV71dTgm4JbofHXj7fuxRm/blmgnlUhAA6mxKVzTk6fSv5BpYR7TIh1Q=" Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:11 music volumio[26037]: info: New Spotify access tokenBQAto8znuj... Feb 17 09:37:11 music volumio[26037]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:37:11 music volumio[26037]: info: Starting Shairport Sync Feb 17 09:37:11 music volumio[26037]: info: Starting Shairport Sync Feb 17 09:37:11 music volumio[26037]: info: Starting Shairport Sync Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=debug msg="completed challenge" Feb 17 09:37:11 music sudo[26248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:37:11 music sudo[26248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:11 music sudo[26246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:37:11 music sudo[26246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:11 music sudo[26250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:37:11 music sudo[26250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:11 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:11 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:37:11 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:37:11 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:37:11 music systemd[1]: shairport-sync.service: Consumed 1.849s CPU time. Feb 17 09:37:11 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:37:11 music sudo[26248]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:11 music sudo[26246]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:11 music volumio[26037]: info: Shairport-Sync Started Feb 17 09:37:11 music volumio[26037]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:37:11 music sudo[26250]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:11 music volumio[26037]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 17 09:37:11 music volumio[26037]: info: Shairport-Sync Started Feb 17 09:37:11 music volumio[26037]: info: Shairport-Sync Started Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioGetVisibleSources Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:11 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioGetQueue Feb 17 09:37:11 music volumio[26037]: info: CoreStateMachine::getQueue Feb 17 09:37:11 music volumio[26037]: info: CorePlayQueue::getQueue Feb 17 09:37:11 music volumio[26037]: info: Listing playlists Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 17 09:37:11 music volumio[26037]: info: Received Get System Info Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:37:11 music volumio[26037]: info: Discovery: Getting this device information Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:11 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:11 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:11 music volumio[26037]: SPOTIFY: User informations: {"country":"US","display_name":"Clipinger Sporing Law","email":"maryalyce@cliplaw.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mltxw4dg22kb3gk2jynmhfuwt4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31mltxw4dg22kb3gk2jynmhfuwt4","id":"31mltxw4dg22kb3gk2jynmhfuwt4","images":[],"product":"premium","type":"user","uri":"spotify:user:31mltxw4dg22kb3gk2jynmhfuwt4"} Feb 17 09:37:11 music volumio[26037]: info: Spotify Successfully logged in Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:11 music volumio[26037]: info: [1771339031623] CoreMusicLibrary::Adding element Spotify Feb 17 09:37:11 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:11 music volumio[26037]: Cannot find translation for source Spotify Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=debug msg="completed challenge" Feb 17 09:37:11 music go-librespot[26226]: time="2026-02-17T09:37:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:12 music go-librespot[26226]: time="2026-02-17T09:37:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:37:12 music go-librespot[26226]: time="2026-02-17T09:37:12-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:12 music go-librespot[26226]: time="2026-02-17T09:37:12-05:00" level=debug msg="completed challenge" Feb 17 09:37:12 music go-librespot[26226]: time="2026-02-17T09:37:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:13 music go-librespot[26226]: time="2026-02-17T09:37:13-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:37:13 music go-librespot[26226]: time="2026-02-17T09:37:13-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:13 music go-librespot[26226]: time="2026-02-17T09:37:13-05:00" level=debug msg="completed challenge" Feb 17 09:37:13 music mpd[26210]: 2026-02-17T09:37:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:37:13 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:37:13 music sudo[26168]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:13 music sudo[26179]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:13 music go-librespot[26226]: time="2026-02-17T09:37:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:13 music volumio[26037]: info: Completed starting Core Plugins Feb 17 09:37:13 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:13 music volumio[26037]: info: ----- MyVolumio plugins startup ---- Feb 17 09:37:13 music volumio[26037]: info: ------------------------------------------- Feb 17 09:37:13 music volumio[26037]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:37:13 music volumio[26037]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:37:13 music volumio[26037]: assert.ok(self.idling) Feb 17 09:37:13 music volumio[26037]: error: The expression evaluated to a falsy value: Feb 17 09:37:13 music volumio[26037]: assert.ok(self.idling) Feb 17 09:37:13 music volumio[26037]: info: MPD running with PID26210 Feb 17 09:37:13 music volumio[26037]: ,establishing connection Feb 17 09:37:13 music volumio[26037]: error: updateQueue error: null Feb 17 09:37:13 music volumio[26037]: error: updateQueue error: null Feb 17 09:37:13 music volumio[26037]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:13 music volumio[26037]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:13 music sudo[26307]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:37:13 music sudo[26307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:13 music sudo[26309]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:37:13 music sudo[26307]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:13 music sudo[26309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:13 music sudo[26309]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:13 music sudo[26312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:37:13 music sudo[26312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:13 music go-librespot[26226]: time="2026-02-17T09:37:13-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:37:13 music sudo[26312]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:13 music volumio[26037]: info: Upmpdcli Daemon Started Feb 17 09:37:13 music volumio[26037]: info: go-librespot daemon successfully initialized Feb 17 09:37:14 music go-librespot[26226]: time="2026-02-17T09:37:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:56382->104.199.241.202:443: read: connection reset by peer" Feb 17 09:37:14 music go-librespot[26226]: time="2026-02-17T09:37:14-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 17 09:37:14 music go-librespot[26226]: time="2026-02-17T09:37:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:34952->104.199.65.9:80: read: connection reset by peer" Feb 17 09:37:14 music go-librespot[26226]: time="2026-02-17T09:37:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:34952->104.199.65.9:80: read: connection reset by peer" Feb 17 09:37:14 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:14 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:37:16 music volumio[26037]: info: Initializing connection to go-librespot Websocket Feb 17 09:37:16 music volumio[26037]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:37:18 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 09:37:18 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:18 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:18 music go-librespot[26315]: go-librespot daemon starting... Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="app state loaded" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:18 music volumio[26037]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=info msg="zeroconf server listening on port 38295" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="obtained new client token: AAAveUHT5iTUdtjfIN8RMSHvjl0vJBxMwvZe4Pf1L2u6CH5e5QB7Wz6Md5OPy8ECV9gpAKz175AHF4BDxjplDFmNbKoJ6e+XWn1bBuXl03csLv+SBK2qTOFfQvWlYuLmVyZsYVeZyMT71mIUjlIymtLvsxB8aEQ4c/rFrtZYtsEcsCUw0/iroDwoLLXnqmgDrfp+PI10r0UAqyDK4rhtkcnsETmFefjhP7B5q2+g3u1tl9ujpMtr+3Q=" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=debug msg="completed challenge" Feb 17 09:37:18 music go-librespot[26316]: time="2026-02-17T09:37:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:19 music go-librespot[26316]: time="2026-02-17T09:37:19-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 17 09:37:19 music go-librespot[26316]: time="2026-02-17T09:37:19-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 17 09:37:19 music go-librespot[26316]: time="2026-02-17T09:37:19-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:37:19 music go-librespot[26316]: time="2026-02-17T09:37:19-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:19 music go-librespot[26316]: time="2026-02-17T09:37:19-05:00" level=debug msg="completed challenge" Feb 17 09:37:19 music go-librespot[26316]: time="2026-02-17T09:37:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:20 music volumio[26037]: info: Initializing connection to go-librespot Websocket Feb 17 09:37:20 music go-librespot[26316]: time="2026-02-17T09:37:20-05:00" level=debug msg="new websocket client" Feb 17 09:37:20 music volumio[26037]: info: Connection to go-librespot Websocket established Feb 17 09:37:20 music go-librespot[26316]: time="2026-02-17T09:37:20-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 17 09:37:20 music go-librespot[26316]: time="2026-02-17T09:37:20-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 17 09:37:20 music go-librespot[26316]: time="2026-02-17T09:37:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:42754->104.199.65.9:80: read: connection reset by peer" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=debug msg="completed challenge" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:37:21 music volumio[26037]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:37:21 music volumio[26037]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=debug msg="completed challenge" Feb 17 09:37:21 music go-librespot[26316]: time="2026-02-17T09:37:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:22 music go-librespot[26316]: time="2026-02-17T09:37:22-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:37:22 music volumio[26037]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:37:22 music volumio[26037]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:37:22 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:22 music volumio[26037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:22 music volumio[26037]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:37:22 music go-librespot[26316]: time="2026-02-17T09:37:22-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:22 music go-librespot[26316]: time="2026-02-17T09:37:22-05:00" level=debug msg="completed challenge" Feb 17 09:37:22 music volumio[26037]: info: MyVolumio login type: Token Feb 17 09:37:22 music volumio[26037]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:37:22 music volumio[26037]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:37:22 music go-librespot[26316]: time="2026-02-17T09:37:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:22 music go-librespot[26316]: time="2026-02-17T09:37:22-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:22 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:22 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:37:23 music volumio[26037]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:37:23 music volumio[26037]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:37:23 music volumio[26037]: info: Streaming services startup Feb 17 09:37:23 music volumio[26037]: info: Starting Streaming Daemon Feb 17 09:37:23 music sudo[26327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:37:23 music sudo[26327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:23 music volumio[26037]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:37:23 music sudo[26327]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:23 music volumio[26037]: info: Getting Spotify volume Feb 17 09:37:23 music volumio[26037]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:37:23 music volumio[26037]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:37:23 music volumio[26037]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:37:23 music volumio[26037]: errno: -111, Feb 17 09:37:23 music volumio[26037]: code: 'ECONNREFUSED', Feb 17 09:37:23 music volumio[26037]: syscall: 'connect', Feb 17 09:37:23 music volumio[26037]: address: '127.0.0.1', Feb 17 09:37:23 music volumio[26037]: port: 9879, Feb 17 09:37:23 music volumio[26037]: response: undefined Feb 17 09:37:23 music volumio[26037]: } Feb 17 09:37:23 music volumio[26037]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:37:24 music sudo[26362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:36' Feb 17 09:37:24 music sudo[26362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:24 music sudo[26362]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:24 music volumio5-onboarding[32661]: time=2026-02-17T09:37:24.758-05:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 17 09:37:24 music volumio-remote-updater[11935]: [2026-02-17 09:37:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:37:24 music volumio-remote-updater[11935]: [2026-02-17 09:37:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:37:24 music volumio5-onboarding[32661]: time=2026-02-17T09:37:24.763-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:48694->127.0.0.1:3000: read: connection reset by peer" Feb 17 09:37:24 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:24 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:37:24 music systemd[1]: volumio.service: Consumed 26.608s CPU time. Feb 17 09:37:24 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:37:24 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:37:25 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3247. Feb 17 09:37:25 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:37:25 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:37:25 music systemd[1]: volumio.service: Consumed 26.608s CPU time. Feb 17 09:37:25 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:37:25 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:37:25 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 09:37:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:25 music volumio5-onboarding[32661]: time=2026-02-17T09:37:25.766-05:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 17 09:37:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:25 music go-librespot[26389]: go-librespot daemon starting... Feb 17 09:37:25 music go-librespot[26390]: time="2026-02-17T09:37:25-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:25 music go-librespot[26390]: time="2026-02-17T09:37:25-05:00" level=debug msg="app state loaded" Feb 17 09:37:25 music go-librespot[26390]: time="2026-02-17T09:37:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=info msg="zeroconf server listening on port 46827" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="obtained new client token: AAANq5haaPtIEygIFeQS2HM48aAgfaT/ozFh3XYxMyW06jbltHSedYPaGwbvdiO2s2RAvzPBgZLnov6J6tCd/c/esj4IxwH0rjUx7HJ5yTDM3wDu5HuwwS/eQjDoKfQvyB49Z5BEZtZYOs96zEUTHWgiH8iqnbocpMTn6jlJDH3tEiN9nXPejXp9ZQObwZByJFku4/3HpoMzSehhSS9pd+lxeJujSola/J+FkU4DWOF5hnv94bElwTs=" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=debug msg="completed challenge" Feb 17 09:37:26 music go-librespot[26390]: time="2026-02-17T09:37:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:27 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:27 music volumio[26374]: info: ----- Volumio3 ---- Feb 17 09:37:27 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:27 music volumio[26374]: info: ----- System startup ---- Feb 17 09:37:27 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:27 music go-librespot[26390]: time="2026-02-17T09:37:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:37:27 music go-librespot[26390]: time="2026-02-17T09:37:27-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:27 music go-librespot[26390]: time="2026-02-17T09:37:27-05:00" level=debug msg="completed challenge" Feb 17 09:37:27 music go-librespot[26390]: time="2026-02-17T09:37:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:27 music go-librespot[26390]: time="2026-02-17T09:37:27-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 17 09:37:27 music volumio[26374]: info: MYVOLUMIO Environment detected Feb 17 09:37:27 music go-librespot[26390]: time="2026-02-17T09:37:27-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:37:27 music volumio[26374]: info: Plugin folders cleanup Feb 17 09:37:27 music volumio[26374]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:37:27 music volumio[26374]: info: Scanning category audio_interface Feb 17 09:37:27 music volumio[26374]: info: Scanning category miscellanea Feb 17 09:37:27 music volumio[26374]: info: Scanning category music_service Feb 17 09:37:27 music volumio[26374]: info: Scanning category plugins.json Feb 17 09:37:27 music volumio[26374]: info: Scanning category system_controller Feb 17 09:37:27 music volumio[26374]: info: Scanning category user_interface Feb 17 09:37:27 music volumio[26374]: info: Scanning into folder /data/plugins/ Feb 17 09:37:27 music volumio[26374]: info: Scanning category music_service Feb 17 09:37:27 music volumio[26374]: info: Plugin folders cleanup completed Feb 17 09:37:27 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:27 music volumio[26374]: info: ----- Core plugins startup ---- Feb 17 09:37:27 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:27 music volumio[26374]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:37:27 music volumio[26374]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:37:27 music volumio[26374]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:37:27 music volumio[26374]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:37:27 music volumio[26374]: info: Loading plugins from folder /data/plugins/ Feb 17 09:37:27 music volumio[26374]: info: Loading plugin "system"... Feb 17 09:37:28 music go-librespot[26390]: time="2026-02-17T09:37:28-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:28 music go-librespot[26390]: time="2026-02-17T09:37:28-05:00" level=debug msg="completed challenge" Feb 17 09:37:28 music volumio[26374]: info: Loading plugin "appearance"... Feb 17 09:37:28 music go-librespot[26390]: time="2026-02-17T09:37:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:28 music go-librespot[26390]: time="2026-02-17T09:37:28-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 17 09:37:28 music go-librespot[26390]: time="2026-02-17T09:37:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:34988->104.199.65.9:443: read: connection reset by peer" Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "network"... Feb 17 09:37:29 music volumio[26374]: info: Refreshing Cached IP Addresses Feb 17 09:37:29 music sudo[26412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:37:29 music sudo[26412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:29 music sudo[26414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:37:29 music sudo[26414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "services"... Feb 17 09:37:29 music sudo[26412]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "volumio5onboarding"... Feb 17 09:37:29 music sudo[26414]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:29 music sudo[26422]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:37:29 music sudo[26422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "alsa_controller"... Feb 17 09:37:29 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "wizard"... Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "networkfs"... Feb 17 09:37:29 music volumio[26374]: info: Starting Udev Watcher for removable devices Feb 17 09:37:29 music volumio[26374]: info: Ignoring mount for partition: boot Feb 17 09:37:29 music volumio[26374]: info: Ignoring mount for partition: volumio Feb 17 09:37:29 music volumio[26374]: info: Ignoring mount for partition: volumio_data Feb 17 09:37:29 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "upnp"... Feb 17 09:37:29 music volumio[26374]: info: [1771339049358] Starting Upmpd Daemon Feb 17 09:37:29 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "my_music"... Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "mpd"... Feb 17 09:37:29 music go-librespot[26390]: time="2026-02-17T09:37:29-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:37:29 music go-librespot[26390]: time="2026-02-17T09:37:29-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:29 music go-librespot[26390]: time="2026-02-17T09:37:29-05:00" level=debug msg="completed challenge" Feb 17 09:37:29 music volumio[26374]: info: Loading plugin "upnp_browser"... Feb 17 09:37:29 music volumio-remote-updater[11935]: [2026-02-17 09:37:29] [connect] Successful connection Feb 17 09:37:29 music sudo[26422]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:29 music go-librespot[26390]: time="2026-02-17T09:37:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:30 music go-librespot[26390]: time="2026-02-17T09:37:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:30 music go-librespot[26390]: time="2026-02-17T09:37:30-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:30 music go-librespot[26390]: time="2026-02-17T09:37:30-05:00" level=debug msg="completed challenge" Feb 17 09:37:30 music go-librespot[26390]: time="2026-02-17T09:37:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:30 music go-librespot[26390]: time="2026-02-17T09:37:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:37:31 music volumio[26374]: info: Starting UPNP Browser Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "alarm-clock"... Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "airplay_emulation"... Feb 17 09:37:31 music volumio[26374]: info: Starting Shairport Sync Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "last_100"... Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "webradio"... Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "i2s_dacs"... Feb 17 09:37:31 music volumio[26374]: info: I2S DAC not set, start Auto-detection Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "volumiodiscovery"... Feb 17 09:37:31 music volumio[26374]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:31 music volumio[26374]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:31 music volumio[26374]: *** WARNING *** For more information see Feb 17 09:37:31 music volumio[26374]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:31 music volumio[26374]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:31 music volumio[26374]: *** WARNING *** For more information see Feb 17 09:37:31 music node[26374]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:31 music node[26374]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:31 music node[26374]: *** WARNING *** For more information see Feb 17 09:37:31 music node[26374]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:37:31 music node[26374]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:37:31 music node[26374]: *** WARNING *** For more information see Feb 17 09:37:31 music volumio[26374]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:37:31 music volumio[26374]: info: Discovery: Started advertising with name: music Feb 17 09:37:31 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:37:31 music volumio[26374]: info: Loading plugin "spop"... Feb 17 09:37:32 music volumio[26374]: info: Loading plugin "outputs"... Feb 17 09:37:32 music volumio[26374]: info: Loading plugin "albumart"... Feb 17 09:37:32 music volumio[26374]: info: Plugin example_plugin is not enabled Feb 17 09:37:32 music volumio[26374]: info: Loading plugin "inputs"... Feb 17 09:37:32 music volumio[26374]: info: Loading plugin "updater_comm"... Feb 17 09:37:32 music volumio[26374]: info: Plugin mpdemulation is not enabled Feb 17 09:37:32 music volumio[26374]: info: Loading plugin "rest_api"... Feb 17 09:37:32 music volumio[26374]: info: Loading plugin "websocket"... Feb 17 09:37:32 music volumio[26374]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:37:32 music volumio[26374]: info: Loading i18n strings for locale en Feb 17 09:37:32 music volumio[26374]: Updating browse sources language Feb 17 09:37:32 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::initPlayerControls Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:37:33 music volumio[26374]: Express server listening on port 3000 Feb 17 09:37:33 music volumio[26374]: [Metrics] WebUI: 6s 538.68ms Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::resetVolumioState Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::getcurrentVolume Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:37:33 music volumio[26447]: Forking 3 albumart workers Feb 17 09:37:33 music volumio[26374]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 17 09:37:33 music volumio[26374]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::pushState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::updateTrackBlock Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrackBlock Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:37:33 music volumio[26374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 17 09:37:33 music volumio[26374]: info: Reloading queue from file Feb 17 09:37:33 music volumio[26374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 17 09:37:33 music volumio[26374]: info: Received Get System Info Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 09:37:33 music volumio[26374]: info: Discovery: Getting this device information Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 09:37:33 music volumio[26374]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::pushState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::setRandom null Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::pushState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:33 music volumio[26374]: info: Setting Device type: Raspberry PI Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 17 09:37:33 music volumio-remote-updater[11935]: [2026-02-17 09:37:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771339049 101 Feb 17 09:37:33 music volumio[26374]: 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: 4 Feb 17 09:37:33 music volumio[26374]: info: VolumeController:: Volume=73 Mute =false Feb 17 09:37:33 music volumio[26374]: info: CoreStateMachine::pushState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioPushState Feb 17 09:37:33 music volumio[26374]: info: Completed loading Core Plugins Feb 17 09:37:33 music volumio[26374]: info: Preparing to generate the ALSA configuration file Feb 17 09:37:33 music volumio[26374]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:37:33 music volumio[26374]: info: Discovery: Found device music Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music volumio[26374]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 17 09:37:33 music volumio[26374]: info: Discovery: Found device music Feb 17 09:37:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:33 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:33 music go-librespot[26500]: go-librespot daemon starting... Feb 17 09:37:33 music volumio[26374]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:37:33 music volumio[26374]: info: Output device has changed, restarting MPD Feb 17 09:37:33 music go-librespot[26501]: time="2026-02-17T09:37:33-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:33 music go-librespot[26501]: time="2026-02-17T09:37:33-05:00" level=debug msg="app state loaded" Feb 17 09:37:33 music volumio[26374]: info: Output device has changed, restarting Shairport Sync Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:33 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:33 music go-librespot[26501]: time="2026-02-17T09:37:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:33 music sudo[26508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:37:33 music sudo[26508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:33 music sudo[26511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:37:33 music sudo[26511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:33 music sudo[26508]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:33 music volumio[26374]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:37:33 music volumio[26374]: info: ___________ START PLUGINS ___________ Feb 17 09:37:34 music volumio[26374]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:37:34 music volumio[26374]: info: Creating MPD Configuration file Feb 17 09:37:34 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:37:34 music sudo[26520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 17 09:37:34 music sudo[26520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:34 music volumio[26374]: info: [1771339054105] CoreMusicLibrary::Adding element Media Servers Feb 17 09:37:34 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:37:34 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:37:34 music systemd[1]: mpd.service: Consumed 4.093s CPU time. Feb 17 09:37:34 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:34 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:37:34 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:37:34 music sudo[26522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:37:34 music sudo[26522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:34 music sudo[26522]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:34 music volumio[26374]: info: UPNP Browser: Client initialized successfully Feb 17 09:37:34 music sudo[26525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:37:34 music sudo[26525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:34 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:37:34 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:37:34 music volumio[26374]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:34 music systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:37:34 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:37:34 music sudo[26520]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:34 music systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:37:34 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:37:34 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:37:34 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:37:34 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:37:34 music volumio[26374]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:34 music volumio[26374]: info: [1771339054411] CoreMusicLibrary::Adding element Last_100 Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:34 music volumio[26374]: info: [1771339054427] CoreMusicLibrary::Adding element Webradio Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=info msg="zeroconf server listening on port 43755" Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:37:34 music volumio[26374]: info: Initializing BBC Radios Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:34 music volumio[26374]: info: Creating Spotify config file Feb 17 09:37:34 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="obtained new client token: AABfMjkH5mKJaWO4dGt67kIimy0ntDQEY1yoiUR35OL0LmIHFmn2fL0YiUxk1oW32/UiJjRq5yiU/nxlfyrJnL1eYAp7/3qtxiOvAwHFdK8cJsICsgNMnVeOullVyYsGqngLR3zIvVUzYmqWXd6gq3NLH5qfYNBmZPsLv6+XurQVm7hzJfdBTaJfqJV6XhaHkCEuUDlUOkvj82ZdcKN9JzaXS0l6upDkBt1zp5NAUOjquVLuZcaBj20=" Feb 17 09:37:34 music sudo[26540]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:37:34 music sudo[26540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:37:34 music sudo[26540]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=debug msg="completed challenge" Feb 17 09:37:34 music go-librespot[26501]: time="2026-02-17T09:37:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:35 music volumio[26374]: info: Volumio Calling Home Feb 17 09:37:35 music volumio[26462]: Starting albumart workers Feb 17 09:37:35 music go-librespot[26501]: time="2026-02-17T09:37:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:37:35 music volumio[26463]: Starting albumart workers Feb 17 09:37:35 music go-librespot[26501]: time="2026-02-17T09:37:35-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:35 music go-librespot[26501]: time="2026-02-17T09:37:35-05:00" level=debug msg="completed challenge" Feb 17 09:37:35 music go-librespot[26501]: time="2026-02-17T09:37:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:35 music volumio[26464]: Starting albumart workers Feb 17 09:37:35 music volumio[26374]: verbose: New Socket.io Connection to 192.168.3.63 from 192.168.1.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Feb 17 09:37:35 music volumio[26374]: info: MPD Permissions set Feb 17 09:37:35 music volumio[26374]: info: MPD Permissions set Feb 17 09:37:35 music volumio[26374]: info: Listing playlists Feb 17 09:37:35 music volumio[26374]: info: Listing playlists Feb 17 09:37:35 music volumio[26374]: info: Spotify config file written Feb 17 09:37:35 music volumio[26374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music sudo[26560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:37:35 music sudo[26560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:35 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:36 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:36 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:37:36 music volumio[26374]: info: No need to fix Spotify hosts Feb 17 09:37:36 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 09:37:36 music systemd[1]: go-librespot-daemon.service: Killing process 26529 (go-librespot) with signal SIGKILL. Feb 17 09:37:36 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 09:37:36 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:36 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:36 music go-librespot[26572]: go-librespot daemon starting... Feb 17 09:37:36 music sudo[26560]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=debug msg="app state loaded" Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:36 music volumio[26374]: info: Volumio called home Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=info msg="zeroconf server listening on port 40619" Feb 17 09:37:36 music volumio[26374]: info: New Spotify access tokenBQAM8kTAtL... Feb 17 09:37:36 music volumio[26374]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:37:36 music volumio[26374]: info: Starting Shairport Sync Feb 17 09:37:36 music volumio[26374]: info: Starting Shairport Sync Feb 17 09:37:36 music volumio[26374]: info: Starting Shairport Sync Feb 17 09:37:36 music sudo[26596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:37:36 music sudo[26596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:36 music sudo[26598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:37:36 music sudo[26598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:36 music sudo[26600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:37:36 music sudo[26600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" level=debug msg="obtained new client token: AAC/NilOk0p9BbsdoG198Xl3qGjl7GOcrKmn89GrFB3zKAEnUrO+GhPnF35XdvrSgoG2eEJZBByiu/RmkiKL6ipNlg2ZAkZtvjI/lIiPoUoV6KIMZHV6u7QtgB2zttSKKLWfZxcqfEH6lQtbce99qw01jgkC2Q0loFC5s/oMz8SBOGRhOgPX0SSYhGY06f0/Yh/CAEWb9AdBPp+UEONv38Lf7NtCNSZe8Gd+h5Qm/Sz3mNl/8EcCfsM=" Feb 17 09:37:36 music volumio[26374]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:36 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:36 music go-librespot[26573]: time="2026-02-17T09:37:36-05:00" 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 17 09:37:36 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:37:36 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:37:36 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:37:36 music systemd[1]: shairport-sync.service: Consumed 1.882s CPU time. Feb 17 09:37:37 music go-librespot[26573]: time="2026-02-17T09:37:37-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 17 09:37:37 music volumio[26374]: SPOTIFY: User informations: {"country":"US","display_name":"Clipinger Sporing Law","email":"maryalyce@cliplaw.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mltxw4dg22kb3gk2jynmhfuwt4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31mltxw4dg22kb3gk2jynmhfuwt4","id":"31mltxw4dg22kb3gk2jynmhfuwt4","images":[],"product":"premium","type":"user","uri":"spotify:user:31mltxw4dg22kb3gk2jynmhfuwt4"} Feb 17 09:37:37 music volumio[26374]: info: Spotify Successfully logged in Feb 17 09:37:37 music volumio[26374]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:37:37 music volumio[26374]: info: [1771339057030] CoreMusicLibrary::Adding element Spotify Feb 17 09:37:37 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:37:37 music volumio[26374]: Cannot find translation for source Spotify Feb 17 09:37:37 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:37:37 music sudo[26596]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:37 music sudo[26598]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:37 music go-librespot[26573]: time="2026-02-17T09:37:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:37:37 music sudo[26600]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:37 music volumio[26374]: info: Shairport-Sync Started Feb 17 09:37:37 music volumio[26374]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:37:37 music volumio[26374]: info: Shairport-Sync Started Feb 17 09:37:37 music volumio[26374]: info: Shairport-Sync Started Feb 17 09:37:37 music go-librespot[26573]: time="2026-02-17T09:37:37-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:37 music go-librespot[26573]: time="2026-02-17T09:37:37-05:00" level=debug msg="completed challenge" Feb 17 09:37:37 music go-librespot[26573]: time="2026-02-17T09:37:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:37 music go-librespot[26573]: time="2026-02-17T09:37:37-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:37:38 music go-librespot[26573]: time="2026-02-17T09:37:38-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 17 09:37:38 music go-librespot[26573]: time="2026-02-17T09:37:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 09:37:38 music mpd[26555]: 2026-02-17T09:37:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:37:38 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:37:38 music sudo[26511]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:38 music sudo[26525]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:38 music volumio[26374]: info: Completed starting Core Plugins Feb 17 09:37:38 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:38 music volumio[26374]: info: ----- MyVolumio plugins startup ---- Feb 17 09:37:38 music volumio[26374]: info: ------------------------------------------- Feb 17 09:37:38 music volumio[26374]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:37:38 music go-librespot[26573]: time="2026-02-17T09:37:38-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 17 09:37:38 music volumio[26374]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:37:38 music volumio[26374]: assert.ok(self.idling) Feb 17 09:37:38 music volumio[26374]: error: The expression evaluated to a falsy value: Feb 17 09:37:38 music volumio[26374]: assert.ok(self.idling) Feb 17 09:37:38 music volumio[26374]: error: updateQueue error: null Feb 17 09:37:38 music volumio[26374]: info: MPD running with PID26555 Feb 17 09:37:38 music volumio[26374]: ,establishing connection Feb 17 09:37:38 music volumio[26374]: error: updateQueue error: null Feb 17 09:37:38 music go-librespot[26573]: time="2026-02-17T09:37:38-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:38 music go-librespot[26573]: time="2026-02-17T09:37:38-05:00" level=debug msg="completed challenge" Feb 17 09:37:39 music go-librespot[26573]: time="2026-02-17T09:37:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:39 music sudo[26645]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:37:39 music sudo[26645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:39 music sudo[26647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:37:39 music sudo[26645]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:39 music sudo[26647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:39 music sudo[26647]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:39 music sudo[26650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:37:39 music sudo[26650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:39 music sudo[26650]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:39 music volumio[26374]: info: Upmpdcli Daemon Started Feb 17 09:37:39 music go-librespot[26573]: time="2026-02-17T09:37:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:39 music volumio[26374]: info: go-librespot daemon successfully initialized Feb 17 09:37:39 music go-librespot[26573]: time="2026-02-17T09:37:39-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:39 music go-librespot[26573]: time="2026-02-17T09:37:39-05:00" level=debug msg="completed challenge" Feb 17 09:37:39 music go-librespot[26573]: time="2026-02-17T09:37:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:40 music go-librespot[26573]: time="2026-02-17T09:37:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:37:40 music go-librespot[26573]: time="2026-02-17T09:37:40-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:40 music go-librespot[26573]: time="2026-02-17T09:37:40-05:00" level=debug msg="completed challenge" Feb 17 09:37:40 music go-librespot[26573]: time="2026-02-17T09:37:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:41 music go-librespot[26573]: time="2026-02-17T09:37:41-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 17 09:37:41 music go-librespot[26573]: time="2026-02-17T09:37:41-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:37:41 music go-librespot[26573]: time="2026-02-17T09:37:41-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:41 music go-librespot[26573]: time="2026-02-17T09:37:41-05:00" level=debug msg="completed challenge" Feb 17 09:37:41 music go-librespot[26573]: time="2026-02-17T09:37:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:41 music go-librespot[26573]: time="2026-02-17T09:37:41-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:41 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:41 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:37:42 music volumio[26374]: info: Initializing connection to go-librespot Websocket Feb 17 09:37:42 music volumio[26374]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:37:43 music volumio[26374]: info: CoreCommandRouter::volumioGetState Feb 17 09:37:43 music volumio[26374]: info: CorePlayQueue::getTrack 0 Feb 17 09:37:43 music volumio[26374]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:37:44 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 09:37:44 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:44 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:37:44 music go-librespot[26654]: go-librespot daemon starting... Feb 17 09:37:44 music go-librespot[26655]: time="2026-02-17T09:37:44-05:00" level=info msg="running go-librespot 0.6.2" Feb 17 09:37:44 music go-librespot[26655]: time="2026-02-17T09:37:44-05:00" level=debug msg="app state loaded" Feb 17 09:37:44 music go-librespot[26655]: time="2026-02-17T09:37:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=info msg="zeroconf server listening on port 40597" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="obtained new client token: AAAYqgIxdyhGmvwu0/JtVswoGwYsIxcQVEkItBd9Wt3F0BFf0DxlR+2Ih2YZBVAVsshsTwPXBhR+adRzOkv7JJMJriAZzzMS0vFpeX2SbxKHb/PXtmHBU+qGi7pe8rkRNf550fDcjt0Yyx4+asDaYjS+q+UmHc7FbPIH2YoPrdzPpNUU2cDYdvivZ4gx/cL+4zAGWoHMtbrdg+V4X9WvDuuAoie3UjWxUjnu2EuVw7C04OTWkJiT3o8=" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="completed challenge" Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:45 music volumio[26374]: info: Initializing connection to go-librespot Websocket Feb 17 09:37:45 music go-librespot[26655]: time="2026-02-17T09:37:45-05:00" level=debug msg="new websocket client" Feb 17 09:37:45 music volumio[26374]: info: Connection to go-librespot Websocket established Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=debug msg="completed challenge" Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=debug msg="completed challenge" Feb 17 09:37:46 music go-librespot[26655]: time="2026-02-17T09:37:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:37:47 music volumio[26374]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:37:47 music volumio[26374]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:37:47 music go-librespot[26655]: time="2026-02-17T09:37:47-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 17 09:37:47 music go-librespot[26655]: time="2026-02-17T09:37:47-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:47 music go-librespot[26655]: time="2026-02-17T09:37:47-05:00" level=debug msg="completed challenge" Feb 17 09:37:47 music go-librespot[26655]: time="2026-02-17T09:37:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:48 music volumio[26374]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:37:48 music volumio[26374]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:37:48 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:48 music volumio[26374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:37:48 music volumio[26374]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:37:48 music volumio[26374]: info: MyVolumio login type: Token Feb 17 09:37:48 music volumio[26374]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:37:48 music go-librespot[26655]: time="2026-02-17T09:37:48-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 17 09:37:48 music volumio[26374]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:37:48 music go-librespot[26655]: time="2026-02-17T09:37:48-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 17 09:37:48 music go-librespot[26655]: time="2026-02-17T09:37:48-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:48 music go-librespot[26655]: time="2026-02-17T09:37:48-05:00" level=debug msg="completed challenge" Feb 17 09:37:48 music go-librespot[26655]: time="2026-02-17T09:37:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:49 music volumio[26374]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:37:49 music volumio[26374]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:37:49 music volumio[26374]: info: Streaming services startup Feb 17 09:37:49 music volumio[26374]: info: Starting Streaming Daemon Feb 17 09:37:49 music sudo[26666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:37:49 music sudo[26666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:37:49 music volumio[26374]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:37:49 music go-librespot[26655]: time="2026-02-17T09:37:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 17 09:37:49 music sudo[26666]: pam_unix(sudo:session): session closed for user root Feb 17 09:37:49 music go-librespot[26655]: time="2026-02-17T09:37:49-05:00" level=debug msg="completed keyexchange" Feb 17 09:37:49 music go-librespot[26655]: time="2026-02-17T09:37:49-05:00" level=debug msg="completed challenge" Feb 17 09:37:49 music volumio[26374]: info: Getting Spotify volume Feb 17 09:37:49 music volumio[26374]: error: Cannot start Volumio Streaming Daemon Feb 17 09:37:49 music volumio[26374]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 09:37:49 music volumio[26374]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 09:37:49 music go-librespot[26655]: time="2026-02-17T09:37:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:49 music go-librespot[26655]: time="2026-02-17T09:37:49-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 09:37:49 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:37:49 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:37:49 music volumio[26374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 17 09:37:49 music volumio[26374]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:37:49 music volumio[26374]: Error: socket hang up Feb 17 09:37:49 music volumio[26374]: at connResetException (node:internal/errors:720:14) Feb 17 09:37:49 music volumio[26374]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 09:37:49 music volumio[26374]: at Socket.emit (node:events:526:35) Feb 17 09:37:49 music volumio[26374]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 09:37:49 music volumio[26374]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 09:37:49 music volumio[26374]: code: 'ECONNRESET', Feb 17 09:37:49 music volumio[26374]: response: undefined Feb 17 09:37:49 music volumio[26374]: } Feb 17 09:37:49 music volumio[26374]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:37:50 music sudo[26700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:36' Feb 17 09:37:50 music sudo[26700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"