Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="app state loaded" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=info msg="zeroconf server listening on port 34895" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="obtained new client token: AACs3nsB+dEPUS6YRLS6mGS0+4rJYh8wVZmxyE5gE8CNGfAhFfzMDvR8R5o20KBH2cyFGlEkeMAeWPzcjGf46hMZ8PXQDsPOeZtkocG1eMcU+i4FAP8cf1heTUQzxWl+y6Tpb0aSpW3b+uFF6q7dhmqYTOpxK22Ml29c6Ly4UKV2YCgaqAJKJxDrn8opLQwxafcms3A2J9YU57b8MeZywMqVw7IUTCgPa2AzW6aaSe/ZmHxu5SB+iu5LWg==" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=debug msg="completed challenge" Dec 09 09:24:00 volumio go-librespot[20080]: time="2025-12-09T09:24:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:01 volumio volumio[19625]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:01 volumio volumio[19625]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin bluetooth to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin multiroom to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin metavolumio to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin cd_controller to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 09 09:24:02 volumio volumio[19625]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 09 09:24:03 volumio volumio[19625]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 09 09:24:03 volumio volumio[19625]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 09 09:24:03 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:03 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:03 volumio volumio[19625]: info: Starting MyVolumio Remote Streaming Endpoints Dec 09 09:24:03 volumio volumio[19625]: info: MyVolumio login type: Token Dec 09 09:24:03 volumio volumio[19625]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 09 09:24:03 volumio volumio[19625]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 09 09:24:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 09 09:24:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:03 volumio go-librespot[20101]: go-librespot daemon starting... Dec 09 09:24:03 volumio go-librespot[20102]: time="2025-12-09T09:24:03-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:03 volumio go-librespot[20102]: time="2025-12-09T09:24:03-06:00" level=debug msg="app state loaded" Dec 09 09:24:03 volumio go-librespot[20102]: time="2025-12-09T09:24:03-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:03 volumio go-librespot[20102]: time="2025-12-09T09:24:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:04 volumio volumio[19625]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 09 09:24:04 volumio volumio[19625]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 09 09:24:04 volumio volumio[19625]: info: Streaming services startup Dec 09 09:24:04 volumio volumio[19625]: info: Starting Streaming Daemon Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=info msg="zeroconf server listening on port 39031" Dec 09 09:24:04 volumio sudo[20111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 09 09:24:04 volumio sudo[20111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:04 volumio volumio[19625]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 09 09:24:04 volumio sudo[20111]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:04 volumio volumio[19625]: error: Cannot start Volumio Streaming Daemon Dec 09 09:24:04 volumio volumio[19625]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 09 09:24:04 volumio volumio[19625]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="obtained new client token: AABwNhn8zBrs6s+hxGibAyWKA6mTDjWTVNn/j+nj6iL8mBkONf1Whl6py9DX/Qj7t8j0JDjhcNQSFeYPvYmIvza+HnH4xTPxwIz4iQSMlHmuvUW6Ufe3jKPvbaACYEuvSaK3YbzMo/HW6GIhKNHFTkZenD2r/fwerYnAnc9oYpt1psw5WtIJTP4l3mDRW+zpl02vr01dadkKbHN9siKRsodbae9/dYR4E4LtoMmelLMiRc23xiRI4aY=" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=debug msg="completed challenge" Dec 09 09:24:04 volumio go-librespot[20102]: time="2025-12-09T09:24:04-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:04 volumio volumio[19625]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 09 09:24:04 volumio volumio[19625]: info: MyVolumio token set successfully Dec 09 09:24:04 volumio volumio[19625]: info: MYVOLUMIO: Adding device Dec 09 09:24:04 volumio volumio[19625]: info: MYVOLUMIO: Evaluating Server Dec 09 09:24:04 volumio volumio[19625]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:04 volumio volumio[19625]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:05 volumio volumio[19625]: info: MyVolumio status changed Dec 09 09:24:05 volumio volumio[19625]: info: Streaming services startup Dec 09 09:24:05 volumio volumio[19625]: info: Starting Streaming Daemon Dec 09 09:24:05 volumio volumio[19625]: info: Removing browser output: myVolumio user plan is not superstar Dec 09 09:24:05 volumio volumio[19625]: info: Removing audio output: Dec 09 09:24:05 volumio volumio[19625]: info: Stoppping Tunnel 1 Dec 09 09:24:05 volumio sudo[20138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 09 09:24:05 volumio sudo[20138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:05 volumio sudo[20140]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 09 09:24:05 volumio sudo[20140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio sudo[20138]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:05 volumio volumio[19625]: error: Cannot start Volumio Streaming Daemon Dec 09 09:24:05 volumio volumio[19625]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 09 09:24:05 volumio volumio[19625]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:05 volumio sudo[20140]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:05 volumio volumio[19625]: info: Remote SSH Stopped Dec 09 09:24:05 volumio volumio[19625]: info: Setting Geolocation for MyVolumio to us4 Dec 09 09:24:05 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:05 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:05 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:05 volumio volumio[19625]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 09 09:24:06 volumio volumio[19625]: info: Updating MyVolumio device info Dec 09 09:24:06 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:06 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:06 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:06 volumio volumio[19625]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 09 09:24:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 09 09:24:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:07 volumio go-librespot[20143]: go-librespot daemon starting... Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=debug msg="app state loaded" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=info msg="zeroconf server listening on port 46275" Dec 09 09:24:07 volumio volumio[19625]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:07 volumio go-librespot[20144]: time="2025-12-09T09:24:07-06:00" level=debug msg="new websocket client" Dec 09 09:24:07 volumio volumio[19625]: info: Connection to go-librespot Websocket established Dec 09 09:24:08 volumio go-librespot[20144]: time="2025-12-09T09:24:08-06:00" level=debug msg="obtained new client token: AABg6RR5UGZ39//geL0wJ+Y6L1oxWP3gfdcP4Efnh5/lSR+6hvK9FRyGsqm1kYcikwkKqLKDEdP4lt8irf8QodUc7t74UdX+kXGQXZhPH7aGuWcHv8nZJrNya0OiucpVgppjf6dGqBeiNjeGiEd/gkLejv8le4TFeC6Vh3kmaidmLPMrbnfIWhBlR2aJkZuNAMqPcKV1quPKikXQYdixHQzbCvl9eaQ6f231plbgsERtS7ff0sXBBnk=" Dec 09 09:24:08 volumio go-librespot[20144]: time="2025-12-09T09:24:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:08 volumio go-librespot[20144]: time="2025-12-09T09:24:08-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:08 volumio go-librespot[20144]: time="2025-12-09T09:24:08-06:00" level=debug msg="completed challenge" Dec 09 09:24:08 volumio go-librespot[20144]: time="2025-12-09T09:24:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:08 volumio volumio[19625]: info: Connection to go-librespot Websocket closed Dec 09 09:24:09 volumio volumio[19625]: info: MYVOLUMIO: Adding device Dec 09 09:24:09 volumio volumio[19625]: info: MYVOLUMIO: Evaluating Server Dec 09 09:24:10 volumio volumio[19625]: info: Setting Geolocation for MyVolumio to us4 Dec 09 09:24:10 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:10 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:10 volumio volumio[19625]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:10 volumio volumio[19625]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 09 09:24:10 volumio volumio[19625]: info: Getting Spotify volume Dec 09 09:24:10 volumio volumio[19625]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 09:24:10 volumio volumio[19625]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:10 volumio volumio[19625]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 09 09:24:10 volumio volumio[19625]: errno: -111, Dec 09 09:24:10 volumio volumio[19625]: code: 'ECONNREFUSED', Dec 09 09:24:10 volumio volumio[19625]: syscall: 'connect', Dec 09 09:24:10 volumio volumio[19625]: address: '127.0.0.1', Dec 09 09:24:10 volumio volumio[19625]: port: 9879, Dec 09 09:24:10 volumio volumio[19625]: response: undefined Dec 09 09:24:10 volumio volumio[19625]: } Dec 09 09:24:10 volumio volumio[19625]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 09:24:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 09 09:24:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:11 volumio go-librespot[20182]: go-librespot daemon starting... Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="app state loaded" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:11 volumio sudo[20192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 09:23' Dec 09 09:24:11 volumio sudo[20192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=info msg="zeroconf server listening on port 43325" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="obtained new client token: AABxOOYZOJkv7ZKJu/cqSvKIfGVbWarhx5mjdeK0H/DpMbOI2yv8Rf9Enq3XY//xd7PWAQHs3R110pfgRxhw26XNzeUoniUBrM3IYy/JwgwnzAx9ctQaPTvxeCU2TXuatHC6XFYPcdA+pq2xYFRmUavlgicBp1DmgcM1Vmr/Sn5KiyjtccgNeE+nn9nUAB8Ji6InYJxtg2SYjaOl8jduAAyCyU4nxkUMkxssDbmAV3U2+CvgHM9jp/VhBg==" Dec 09 09:24:11 volumio sudo[20192]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:11 volumio go-librespot[20183]: time="2025-12-09T09:24:11-06:00" level=debug msg="completed challenge" Dec 09 09:24:11 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 09 09:24:11 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 09 09:24:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 09 09:24:12 volumio systemd[1]: volumio.service: Consumed 46.389s CPU time. Dec 09 09:24:12 volumio go-librespot[20183]: time="2025-12-09T09:24:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 09:24:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 09:24:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24269. Dec 09 09:24:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 09:24:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 09 09:24:12 volumio systemd[1]: volumio.service: Consumed 46.389s CPU time. Dec 09 09:24:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 09 09:24:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 09:24:14 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:14 volumio volumio[20205]: info: ----- Volumio3 ---- Dec 09 09:24:14 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:14 volumio volumio[20205]: info: ----- System startup ---- Dec 09 09:24:14 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:14 volumio volumio[20205]: info: MYVOLUMIO Environment detected Dec 09 09:24:14 volumio volumio[20205]: info: Plugin folders cleanup Dec 09 09:24:14 volumio volumio[20205]: info: Scanning into folder /volumio/app/plugins/ Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category audio_interface Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category miscellanea Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category music_service Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category plugins.json Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category system_controller Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category user_interface Dec 09 09:24:14 volumio volumio[20205]: info: Scanning into folder /data/plugins/ Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category audio_interface Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category music_service Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category system_controller Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category system_hardware Dec 09 09:24:14 volumio volumio[20205]: info: Scanning category user_interface Dec 09 09:24:14 volumio volumio[20205]: info: Plugin folders cleanup completed Dec 09 09:24:14 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:14 volumio volumio[20205]: info: ----- Core plugins startup ---- Dec 09 09:24:14 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:14 volumio volumio[20205]: info: Loading plugins from folder /volumio/app/plugins/ Dec 09 09:24:14 volumio volumio[20205]: info: Adding plugin upnp to MyMusic Plugins Dec 09 09:24:15 volumio volumio[20205]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 09 09:24:15 volumio volumio[20205]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 09 09:24:15 volumio volumio[20205]: info: Loading plugins from folder /data/plugins/ Dec 09 09:24:15 volumio volumio[20205]: info: Loading plugin "system"... Dec 09 09:24:15 volumio volumio[20205]: info: Loading plugin "appearance"... Dec 09 09:24:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 09 09:24:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:15 volumio go-librespot[20235]: go-librespot daemon starting... Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="app state loaded" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=info msg="zeroconf server listening on port 45785" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="obtained new client token: AABkxEVUHgtktamWpdsPTzfFpoDMUmWe7LlMvZWa9oVNxzxke0GIbYeg1Zrn1HnZgJJU4DpKum5BWMXp1S2L2wx9fgorJjQtkqLwpx6kdAyRIOhML9VXd1y6V82juLbQhMPoV86OYoquaf4hn1sDyJ+yWUq6F7DJqd/YN2RUrgpFlVBBlazhhqI1WrgmJLKQF+mjNekgyq5E3pqP0p5tiNTCu1l4HlmmiIozjeLfyYJziBsBAsJNP82/xQ==" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=debug msg="completed challenge" Dec 09 09:24:15 volumio go-librespot[20236]: time="2025-12-09T09:24:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "network"... Dec 09 09:24:16 volumio volumio[20205]: info: Refreshing Cached IP Addresses Dec 09 09:24:16 volumio sudo[20244]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 09:24:16 volumio sudo[20246]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 09:24:16 volumio sudo[20246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:16 volumio sudo[20244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "services"... Dec 09 09:24:16 volumio sudo[20244]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:16 volumio sudo[20246]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "alsa_controller"... Dec 09 09:24:16 volumio sudo[20253]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 09 09:24:16 volumio sudo[20253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:16 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "wizard"... Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "networkfs"... Dec 09 09:24:16 volumio volumio[20205]: info: Starting Udev Watcher for removable devices Dec 09 09:24:16 volumio volumio[20205]: info: Ignoring mount for partition: boot Dec 09 09:24:16 volumio volumio[20205]: info: Ignoring mount for partition: volumio Dec 09 09:24:16 volumio volumio[20205]: info: Ignoring mount for partition: volumio_data Dec 09 09:24:16 volumio volumio[20205]: info: Mounting Device Wikipedia Dec 09 09:24:16 volumio sudo[20283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 09 09:24:16 volumio sudo[20283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:16 volumio sudo[20283]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:16 volumio volumio[20205]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 09:24:16 volumio volumio[20205]: dmesg(1) may have more information after failed mount system call. Dec 09 09:24:16 volumio volumio[20205]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 09 09:24:16 volumio volumio[20205]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 09:24:16 volumio volumio[20205]: dmesg(1) may have more information after failed mount system call. Dec 09 09:24:16 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "volumio_command_line_client"... Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "upnp"... Dec 09 09:24:16 volumio volumio[20205]: info: [1765293856479] Starting Upmpd Daemon Dec 09 09:24:16 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "my_music"... Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "mpd"... Dec 09 09:24:16 volumio volumio[20205]: info: Loading plugin "upnp_browser"... Dec 09 09:24:16 volumio sudo[20253]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:16 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:16] [connect] Successful connection Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "alarm-clock"... Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "airplay_emulation"... Dec 09 09:24:18 volumio volumio[20205]: info: Starting Shairport Sync Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "last_100"... Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "webradio"... Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "i2s_dacs"... Dec 09 09:24:18 volumio volumio[20205]: info: I2S DAC not set, start Auto-detection Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "volumiodiscovery"... Dec 09 09:24:18 volumio volumio[20205]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:18 volumio volumio[20205]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:18 volumio volumio[20205]: *** WARNING *** For more information see Dec 09 09:24:18 volumio volumio[20205]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:18 volumio volumio[20205]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:18 volumio volumio[20205]: *** WARNING *** For more information see Dec 09 09:24:18 volumio node[20205]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:18 volumio node[20205]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:18 volumio node[20205]: *** WARNING *** For more information see Dec 09 09:24:18 volumio node[20205]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:18 volumio node[20205]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:18 volumio node[20205]: *** WARNING *** For more information see Dec 09 09:24:18 volumio volumio[20205]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 09 09:24:18 volumio volumio[20205]: info: Discovery: Started advertising with name: Volumio Dec 09 09:24:18 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 09:24:18 volumio volumio[20205]: info: Loading plugin "bandcamp"... Dec 09 09:24:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 09 09:24:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:19 volumio go-librespot[20287]: go-librespot daemon starting... Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="app state loaded" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=info msg="zeroconf server listening on port 42777" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="obtained new client token: AABtZbx65idVMMgWJa0jB09LwnTFCnzvsx/DMaU7uJZ5ZtDej2/5GMBQMQo0n7XYzANwZc0wf+D9zA2zKWBnKi+X0MgJ3+blr4CWlqrvzMvvEWOXbW5/xgy34dl1oheICQHEYe1cVXmX3Fdf6qZ9qYVyl+IdeEfWaRWaVRYoDjVN7oM4hpilJdRwB9U49KGzmlTkHUEjg+N1oQ/Uencyvvquvqo3AtrorVWsVBJJOyhkfk9OCfXlcwAuMA==" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=debug msg="completed challenge" Dec 09 09:24:19 volumio go-librespot[20288]: time="2025-12-09T09:24:19-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:19 volumio volumio[20205]: info: Plugin calmradio is not enabled Dec 09 09:24:19 volumio volumio[20205]: info: Loading plugin "soundcloud"... Dec 09 09:24:20 volumio volumio[20205]: info: Loading plugin "spop"... Dec 09 09:24:21 volumio volumio[20205]: info: Loading plugin "squeezelite_mc"... Dec 09 09:24:21 volumio volumio[20205]: info: Loading plugin "youtube2"... Dec 09 09:24:22 volumio volumio[20205]: info: Loading plugin "ytcr"... Dec 09 09:24:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 09 09:24:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:22 volumio go-librespot[20295]: go-librespot daemon starting... Dec 09 09:24:22 volumio go-librespot[20296]: time="2025-12-09T09:24:22-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:22 volumio go-librespot[20296]: time="2025-12-09T09:24:22-06:00" level=debug msg="app state loaded" Dec 09 09:24:22 volumio go-librespot[20296]: time="2025-12-09T09:24:22-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:22 volumio go-librespot[20296]: time="2025-12-09T09:24:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=info msg="zeroconf server listening on port 37811" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="obtained new client token: AAAsZXuTmy/xmVWhV9kGWrJX6tbOhIdelQupLZff9oiO/C/5HJB+vRdBXiYyHmdNoplXQtLlLy73SIa7vaUVm3QqHWlXq+WmdEYet1Pe0WmoGkw7XSV0AbLyjfv0FiQYSqVNmTlNJovn/NQJQ0ZtsLE7PKJpaRJgaNf442ALWM3PKulY7YytDrSkbD63iA5uke84T51FWuSIJyWmtsLV1tGP3iZqsDJvnHyOv0k3Vsu0eg1zHgFUDME=" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=debug msg="completed challenge" Dec 09 09:24:23 volumio go-librespot[20296]: time="2025-12-09T09:24:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:23 volumio volumio[20205]: info: Loading plugin "ytmusic"... Dec 09 09:24:24 volumio volumio[20205]: info: Plugin now_playing is not enabled Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "outputs"... Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "albumart"... Dec 09 09:24:24 volumio volumio[20205]: info: Plugin example_plugin is not enabled Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "inputs"... Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "updater_comm"... Dec 09 09:24:24 volumio volumio[20205]: info: Plugin mpdemulation is not enabled Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "rest_api"... Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "websocket"... Dec 09 09:24:24 volumio volumio[20205]: info: Starting Socket.io Server version 1.7.4 Dec 09 09:24:24 volumio volumio[20205]: info: Plugin fusiondsp is not enabled Dec 09 09:24:24 volumio volumio[20205]: info: Plugin mpdoutput is not enabled Dec 09 09:24:24 volumio volumio[20205]: info: Plugin RoonBridge is not enabled Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "podcast"... Dec 09 09:24:24 volumio volumio[20205]: info: ControllerPodcast::constructor Dec 09 09:24:24 volumio volumio[20205]: info: Loading plugin "volusonic"... Dec 09 09:24:25 volumio volumio[20303]: Forking 3 albumart workers Dec 09 09:24:26 volumio volumio[20205]: info: Applying required configuration parameters for plugin volusonic Dec 09 09:24:26 volumio volumio[20205]: info: Loading plugin "backup_restore"... Dec 09 09:24:26 volumio volumio[20315]: Starting albumart workers Dec 09 09:24:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 09 09:24:26 volumio volumio[20314]: Starting albumart workers Dec 09 09:24:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:26 volumio volumio[20313]: Starting albumart workers Dec 09 09:24:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:26 volumio go-librespot[20357]: go-librespot daemon starting... Dec 09 09:24:26 volumio go-librespot[20358]: time="2025-12-09T09:24:26-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:26 volumio go-librespot[20358]: time="2025-12-09T09:24:26-06:00" level=debug msg="app state loaded" Dec 09 09:24:26 volumio go-librespot[20358]: time="2025-12-09T09:24:26-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:26 volumio go-librespot[20358]: time="2025-12-09T09:24:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:26 volumio volumio[20205]: info: Applying required configuration parameters for plugin backup_restore Dec 09 09:24:26 volumio volumio[20205]: info: Plugin rpi_eeprom_config is not enabled Dec 09 09:24:26 volumio volumio[20205]: info: Plugin rpi_eeprom_updater is not enabled Dec 09 09:24:26 volumio volumio[20205]: info: Loading plugin "scheduledrestart"... Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=info msg="zeroconf server listening on port 38313" Dec 09 09:24:27 volumio volumio[20205]: info: Applying required configuration parameters for plugin scheduledrestart Dec 09 09:24:27 volumio volumio[20205]: info: Plugin Bluetoothremote is not enabled Dec 09 09:24:27 volumio volumio[20205]: info: Plugin music_services_shield is not enabled Dec 09 09:24:27 volumio volumio[20205]: info: Loading plugin "Systeminfo"... Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="obtained new client token: AAAXQteSQolMPqb9wNHk8z/+WmqfKLpTqsvCRGevPogLQ6oY7pDsKoM74zpwJnUED6kNjntmS0DwAi57p+Uk4xhb2Unz3F3kiCMXE/OWsv+es5ZxRv0qMLW5ozlZhXuQ5WtNJ+F3rHdCo41BAYEOBkZLoxUjG5IaLgDPOs1ItsGK7/fUgw7ckZeMIuW8SQw3fd/bqXvp7RDlD3y1U5ZFagPsyLA/Hv81N1reMiAaLkJkTPOZlIEpohGRmg==" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=debug msg="completed challenge" Dec 09 09:24:27 volumio go-librespot[20358]: time="2025-12-09T09:24:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:27 volumio volumio[20205]: info: Plugin peppymeterbasic is not enabled Dec 09 09:24:27 volumio volumio[20205]: info: Loading plugin "peppyspectrum"... Dec 09 09:24:28 volumio volumio[20205]: info: Loading i18n strings for locale en Dec 09 09:24:28 volumio volumio[20205]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 09:24:28 volumio volumio[20205]: Updating browse sources language Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::initPlayerControls Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: Express server listening on port 3000 Dec 09 09:24:28 volumio volumio[20205]: [Metrics] WebUI: 14s 641.09ms Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::resetVolumioState Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::getcurrentVolume Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:28 volumio sudo[20389]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 09:24:28 volumio sudo[20389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio sudo[20391]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 09:24:28 volumio sudo[20391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio sudo[20389]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:28 volumio sudo[20391]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:28 volumio volumio[20205]: info: Volumio Network Manager: Network status updated: 1 Dec 09 09:24:28 volumio volumio[20205]: info: VolumeController:: Volume=86 Mute =false Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::pushState Dec 09 09:24:28 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioPushState Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::updateTrackBlock Dec 09 09:24:28 volumio volumio[20205]: info: CorePlayQueue::getTrackBlock Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 09:24:28 volumio volumio[20205]: info: Reloading queue from file Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::setRepeat null single undefined Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::pushState Dec 09 09:24:28 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioPushState Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::setRandom null Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::pushState Dec 09 09:24:28 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioPushState Dec 09 09:24:28 volumio volumio[20205]: info: Setting Device type: Raspberry PI Dec 09 09:24:28 volumio volumio[20205]: info: VolumeController:: Volume=86 Mute =false Dec 09 09:24:28 volumio volumio[20205]: info: CoreStateMachine::pushState Dec 09 09:24:28 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioPushState Dec 09 09:24:28 volumio sudo[20405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 09 09:24:28 volumio volumio[20205]: info: Completed loading Core Plugins Dec 09 09:24:28 volumio sudo[20405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio volumio[20205]: info: Preparing to generate the ALSA configuration file Dec 09 09:24:28 volumio volumio[20205]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 09:24:28 volumio volumio[20205]: info: Reading ALSA contributions from plugins. Dec 09 09:24:28 volumio sudo[20405]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:28 volumio volumio[20205]: info: Asound.conf file unchanged, so no further update is needed Dec 09 09:24:28 volumio volumio[20205]: info: Output device has changed, restarting MPD Dec 09 09:24:28 volumio volumio[20205]: info: Output device has changed, restarting Shairport Sync Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:28 volumio sudo[20408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 09:24:28 volumio sudo[20408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio sudo[20408]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:28 volumio sudo[20410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 09:24:28 volumio sudo[20410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio volumio[20205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:24:28 volumio volumio[20205]: info: ___________ START PLUGINS ___________ Dec 09 09:24:28 volumio volumio[20205]: info: ControllerMpd::onStart: Initializing MPD Dec 09 09:24:28 volumio volumio[20205]: info: Creating MPD Configuration file Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:28 volumio volumio[20205]: info: [1765293868809] CoreMusicLibrary::Adding element Media Servers Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 09 09:24:28 volumio sudo[20420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 09:24:28 volumio sudo[20418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 09:24:28 volumio sudo[20420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio sudo[20418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:28 volumio sudo[20418]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:28 volumio volumio[20205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:28 volumio volumio[20205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:28 volumio volumio[20205]: info: [1765293868923] CoreMusicLibrary::Adding element Last_100 Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:28 volumio volumio[20205]: info: [1765293868928] CoreMusicLibrary::Adding element Webradio Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 09:24:28 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 09:24:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 09:24:28 volumio systemd[1]: mpd.service: Consumed 4.481s CPU time. Dec 09 09:24:28 volumio volumio[20205]: info: Initializing BBC Radios Dec 09 09:24:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 09:24:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 09:24:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 09:24:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 09:24:28 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:29 volumio volumio[20205]: info: [1765293869005] CoreMusicLibrary::Adding element Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:29 volumio volumio[20205]: info: [1765293869018] CoreMusicLibrary::Adding element SoundCloud Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: info: Creating Spotify config file Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio sudo[20445]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 09:24:29 volumio sudo[20445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 09:24:29 volumio sudo[20445]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:29 volumio volumio[20205]: info: [squeezelite_mc] Starting proxy server... Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:29 volumio volumio[20205]: info: [1765293869369] CoreMusicLibrary::Adding element YouTube2 Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:29 volumio volumio[20205]: info: [1765293869388] CoreMusicLibrary::Adding element YouTube Music Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube Music Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:29 volumio volumio[20205]: info: [1765293869399] CoreMusicLibrary::Adding element Podcast Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube Music Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Podcast Dec 09 09:24:29 volumio volumio[20205]: info: Loading i18n strings for locale en Dec 09 09:24:29 volumio volumio[20205]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 09:24:29 volumio volumio[20205]: Updating browse sources language Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube Music Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Podcast Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube Music Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Podcast Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:29 volumio volumio[20205]: info: [1765293869447] CoreMusicLibrary::Adding element Volusonic Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source YouTube Music Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Podcast Dec 09 09:24:29 volumio volumio[20205]: Cannot find translation for source Volusonic Dec 09 09:24:29 volumio volumio[20205]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 09 09:24:29 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:29] [connect] Successful connection Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 09 09:24:29 volumio volumio[20205]: info: Volumio Calling Home Dec 09 09:24:29 volumio volumio[20205]: info: [squeezelite_mc] Proxy server started on port 36199 Dec 09 09:24:29 volumio volumio[20205]: info: Preparing to generate the ALSA configuration file Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 09:24:29 volumio volumio[20205]: info: Upmpdcli Daemon Started Dec 09 09:24:29 volumio volumio[20205]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 09:24:29 volumio volumio[20205]: info: Discovery: Found device Volumio Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioGetState Dec 09 09:24:29 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:29 volumio volumio[20205]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 09:24:29 volumio volumio[20205]: info: Discovery: Found device Volumio Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioGetState Dec 09 09:24:29 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:29 volumio volumio[20205]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 09:24:29 volumio volumio[20205]: info: Reading ALSA contributions from plugins. Dec 09 09:24:29 volumio volumio[20205]: info: MPD Permissions set Dec 09 09:24:29 volumio volumio[20205]: info: MPD Permissions set Dec 09 09:24:29 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765293869 101 Dec 09 09:24:29 volumio volumio[20205]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 09 09:24:29 volumio volumio[20205]: info: Spotify config file written Dec 09 09:24:29 volumio sudo[20454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 09 09:24:29 volumio sudo[20454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:29 volumio volumio[20205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 09 09:24:29 volumio volumio[20205]: info: VolumeController:: Volume=86 Mute =false Dec 09 09:24:29 volumio volumio[20205]: info: CoreStateMachine::pushState Dec 09 09:24:29 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::volumioPushState Dec 09 09:24:29 volumio volumio[20205]: info: [squeezelite_mc] Server discovery started Dec 09 09:24:29 volumio volumio[20205]: info: [squeezelite_mc] Player finder started Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:29 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio go-librespot[20456]: go-librespot daemon starting... Dec 09 09:24:30 volumio sudo[20454]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="app state loaded" Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: No need to fix Spotify hosts Dec 09 09:24:30 volumio volumio[20205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 09 09:24:30 volumio volumio[20205]: info: Volumio called home Dec 09 09:24:30 volumio volumio[20205]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 09 09:24:30 volumio volumio[20205]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 09 09:24:30 volumio volumio[20205]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:30 volumio volumio[20205]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 09:24:30 volumio volumio[20205]: SPOTIFY: BQAdRtkSonzbyv2V9uYT3jx8HIg82HJbxjY0XH8cywzEoL6_1Bnn84WsmphuJRfz2tgv-yZ3AlvHjg-QdTjgfrJq_3AR9gd-EtgeUGNfE8xl7x1YG0m6S2qHG5oroHQdJ15i_JdO92Vd6BF9oQeMGWB4mDkJRMkhceghZgRjeLNIucB7hQPVBMV-yQBrm5C_PxUH1FLzwW8VhNHso7jyyaSgYmwW8u1wp6y-hkQ Dec 09 09:24:30 volumio volumio[20205]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 09:24:30 volumio volumio[20205]: info: New Spotify access token = BQAdRtkSonzbyv2V9uYT3jx8HIg82HJbxjY0XH8cywzEoL6_1Bnn84WsmphuJRfz2tgv-yZ3AlvHjg-QdTjgfrJq_3AR9gd-EtgeUGNfE8xl7x1YG0m6S2qHG5oroHQdJ15i_JdO92Vd6BF9oQeMGWB4mDkJRMkhceghZgRjeLNIucB7hQPVBMV-yQBrm5C_PxUH1FLzwW8VhNHso7jyyaSgYmwW8u1wp6y-hkQ Dec 09 09:24:30 volumio volumio[20205]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 09 09:24:30 volumio volumio[20205]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=info msg="zeroconf server listening on port 36183" Dec 09 09:24:30 volumio volumio[20205]: info: Starting Shairport Sync Dec 09 09:24:30 volumio volumio[20205]: info: Starting Shairport Sync Dec 09 09:24:30 volumio volumio[20205]: info: Starting Shairport Sync Dec 09 09:24:30 volumio sudo[20485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:24:30 volumio sudo[20485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio sudo[20483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:24:30 volumio sudo[20483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio volumio[20205]: info: Asound.conf file unchanged, so no further update is needed Dec 09 09:24:30 volumio volumio[20205]: info: Output device has changed, restarting MPD Dec 09 09:24:30 volumio sudo[20481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:24:30 volumio sudo[20481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 09:24:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 09:24:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:24:30 volumio systemd[1]: shairport-sync.service: Consumed 1.870s CPU time. Dec 09 09:24:30 volumio sudo[20478]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 09:24:30 volumio sudo[20478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio volumio[20205]: info: Output device has changed, restarting Shairport Sync Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:30 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:30 volumio sudo[20478]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio volumio[20205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:24:30 volumio sudo[20490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 09:24:30 volumio sudo[20490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio sudo[20498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 09:24:30 volumio sudo[20498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:24:30 volumio sudo[20490]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio sudo[20485]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="obtained new client token: AACBjmq4OVgDLgNNGLDKmlkWzmkcPe0yRn3jjpperRGBzho+PxzAWLANkH6ejzKdsVcGC/JSXgDtznwxqZtrebTPc/YjAKEiDc/bJbbfz5Pe12sOAHc7v9Vw5Zbs/sWQjjFYjKdhZwDTC7OpFVJOS+n1j4+P/E5vSiqyhmpoyMOKQEb/nez8uv+YxSqvO88bvtd0b3Cakhm3Y5TPDKkg92q0FZSxJJjtMGDi7R5MhY9Sn1jAKd5CKcH5GQ==" Dec 09 09:24:30 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 09:24:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 09:24:30 volumio systemd[1]: mpd.service: Consumed 1.749s CPU time. Dec 09 09:24:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 09:24:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:24:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 09:24:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 09:24:30 volumio volumio[20205]: info: MPD Permissions set Dec 09 09:24:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 09:24:30 volumio volumio[20205]: info: Shairport-Sync Started Dec 09 09:24:30 volumio volumio[20205]: Error adding Membership: Error: addMembership EINVAL Dec 09 09:24:30 volumio volumio[20205]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 09 09:24:30 volumio sudo[20520]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 09 09:24:30 volumio sudo[20520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:30 volumio sudo[20520]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 09:24:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 09:24:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:24:30 volumio sudo[20483]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio sudo[20481]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:30 volumio go-librespot[20465]: time="2025-12-09T09:24:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:31 volumio volumio[20205]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio go-librespot[20465]: time="2025-12-09T09:24:31-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio go-librespot[20465]: time="2025-12-09T09:24:31-06:00" level=debug msg="completed challenge" Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:31 volumio go-librespot[20465]: time="2025-12-09T09:24:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:31 volumio volumio[20205]: info: Shairport-Sync Started Dec 09 09:24:31 volumio volumio[20205]: info: Shairport-Sync Started Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::volumioGetState Dec 09 09:24:31 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:31 volumio volumio[20205]: info: Starting Shairport Sync Dec 09 09:24:31 volumio sudo[20550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:24:31 volumio sudo[20550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:31 volumio sudo[20524]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 09:24:31 volumio sudo[20524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 09:24:31 volumio sudo[20524]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:31 volumio sudo[20529]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 09:24:31 volumio sudo[20529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:31 volumio sudo[20529]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:31 volumio volumio[20205]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 09 09:24:31 volumio volumio[20205]: info: Spotify Successfully logged in Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:24:31 volumio volumio[20205]: info: [1765293871309] CoreMusicLibrary::Adding element Spotify Dec 09 09:24:31 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source Bandcamp Discover Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source SoundCloud Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source YouTube2 Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source YouTube Music Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source Podcast Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source Volusonic Dec 09 09:24:31 volumio volumio[20205]: Cannot find translation for source Spotify Dec 09 09:24:31 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 09 09:24:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 09:24:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 09:24:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:24:31 volumio sudo[20556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 09 09:24:31 volumio sudo[20556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:24:31 volumio sudo[20550]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:31 volumio systemd[1]: Reloading. Dec 09 09:24:31 volumio volumio[20205]: info: Shairport-Sync Started Dec 09 09:24:31 volumio volumio[20205]: info: [squeezelite_mc] Notification listener started Dec 09 09:24:31 volumio volumio[20205]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 09:24:32 volumio volumio[20205]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 09:24:32 volumio volumio[20205]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 09:24:32 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:32 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:32 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:24:32 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:24:33 volumio volumio[20205]: info: CoreCommandRouter::volumioGetState Dec 09 09:24:33 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:33 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:33 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:24:33 volumio volumio[20205]: info: go-librespot daemon successfully initialized Dec 09 09:24:33 volumio sudo[20556]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:33 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:33 volumio sudo[20591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:33 volumio sudo[20591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:33 volumio sudo[20591]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:33 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 09 09:24:33 volumio sudo[20594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 09 09:24:33 volumio sudo[20594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:33 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 09:24:33 volumio volumio[20205]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 09 09:24:33 volumio volumio[20205]: info: CoreCommandRouter::volumioGetState Dec 09 09:24:33 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:33 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 09 09:24:33 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 09:24:34 volumio sudo[20594]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 09 09:24:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:34 volumio go-librespot[20596]: go-librespot daemon starting... Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="app state loaded" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:34 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=info msg="zeroconf server listening on port 42617" Dec 09 09:24:34 volumio sudo[20607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:34 volumio sudo[20607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="obtained new client token: AAC2t5IM3WVYP/Jwg45K5Ei3xMwmCXEH9MaMmb76jGTDnkYCTBfPkMwbhVYEy37ZZG11d54Gb8GOUb/EEWCn2OLbmWCwQCDXXpKEbrbavUefZD6ifBbY1Ob/NZfn2xYFvsFTLULU4Uo+gyWnuvAah+rwVlNiqTdHf9o5kDsVKnNqo0wVpN/c8vpz/O3FJKJx6w1goyzxFAaxew1B7dziTbA38P/uFSX9pxdAowvB5hU/jD7FWHAsldAJtw==" Dec 09 09:24:34 volumio sudo[20607]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:34 volumio volumio[20205]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 09 09:24:34 volumio sudo[20611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 09 09:24:34 volumio sudo[20611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:34 volumio sudo[20611]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:34 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:34 volumio sudo[20614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 09 09:24:34 volumio sudo[20614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=debug msg="completed challenge" Dec 09 09:24:34 volumio go-librespot[20597]: time="2025-12-09T09:24:34-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:34 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 09:24:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:34 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 09:24:34 volumio sudo[20614]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:34 volumio mpd[20554]: 2025-12-09T09:24:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 09 09:24:35 volumio volumio[20205]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 09 09:24:35 volumio volumio[20205]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 09:24:35 volumio volumio[20205]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 09:24:35 volumio volumio[20205]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 09:24:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 09 09:24:35 volumio sudo[20410]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:35 volumio sudo[20420]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:35 volumio sudo[20498]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:35 volumio volumio[20205]: error: MPD error: The expression evaluated to a falsy value: Dec 09 09:24:35 volumio volumio[20205]: assert.ok(self.idling) Dec 09 09:24:35 volumio volumio[20205]: error: The expression evaluated to a falsy value: Dec 09 09:24:35 volumio volumio[20205]: assert.ok(self.idling) Dec 09 09:24:35 volumio volumio[20205]: error: MPD error: The expression evaluated to a falsy value: Dec 09 09:24:35 volumio volumio[20205]: assert.ok(self.idling) Dec 09 09:24:35 volumio volumio[20205]: error: The expression evaluated to a falsy value: Dec 09 09:24:35 volumio volumio[20205]: assert.ok(self.idling) Dec 09 09:24:35 volumio volumio[20205]: error: updateQueue error: null Dec 09 09:24:35 volumio volumio[20205]: info: MPD running with PID20554 Dec 09 09:24:35 volumio volumio[20205]: ,establishing connection Dec 09 09:24:35 volumio volumio[20205]: error: updateQueue error: null Dec 09 09:24:35 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:35 volumio sudo[20626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:35 volumio sudo[20626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:35 volumio sudo[20626]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:36 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:36 volumio sudo[20629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:36 volumio sudo[20629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:36 volumio sudo[20629]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:36 volumio volumio[20205]: info: CoreCommandRouter::volumioGetState Dec 09 09:24:36 volumio volumio[20205]: info: CorePlayQueue::getTrack 0 Dec 09 09:24:36 volumio volumio[20205]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:36 volumio volumio[20205]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:36 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:36 volumio sudo[20646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:36 volumio sudo[20646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:36 volumio sudo[20646]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:37 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:37 volumio sudo[20649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:37 volumio sudo[20649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:37 volumio sudo[20649]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:37 volumio volumio[20205]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:24:37 volumio sudo[20652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:24:37 volumio sudo[20652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:37 volumio sudo[20652]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:37 volumio volumio[20205]: info: Completed starting Core Plugins Dec 09 09:24:37 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:37 volumio volumio[20205]: info: ----- MyVolumio plugins startup ---- Dec 09 09:24:37 volumio volumio[20205]: info: ------------------------------------------- Dec 09 09:24:37 volumio volumio[20205]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 09 09:24:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 09 09:24:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:38 volumio go-librespot[20654]: go-librespot daemon starting... Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="app state loaded" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:38 volumio sudo[20663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 09:24:38 volumio sudo[20663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:38 volumio sudo[20665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 09:24:38 volumio sudo[20665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:38 volumio sudo[20667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 09:24:38 volumio sudo[20667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=info msg="zeroconf server listening on port 43571" Dec 09 09:24:38 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 09:24:38 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 09:24:38 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="obtained new client token: AADANyFkO4TvnbM/NwU/ouAZVmCkCdMZHEiFc0Re+c7uRhg/eioOfJZ/DzuBc2vWOo/GSQUsYIKBdOalCGe1383m1AP+vf29AoJPjCVWllTTaHwV5fA2EF7lp+VveuFqIJ1I74UegzS1dkWnUpFZT5WjtHAXisFvJcZHHN2sgD3RrPHlA8bQB2oOgSUYpm1ti1f4mQeH7KygJCKgBg/aIxZhksSsjcogxfpLbiGDSvIQQtgQ/tDDx30Ngg==" Dec 09 09:24:38 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 09:24:38 volumio sudo[20667]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:38 volumio sudo[20665]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:38 volumio sudo[20663]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:38 volumio volumio[20205]: info: Successfully started MPD Monitor Dec 09 09:24:38 volumio mpd_monitor.sh[20671]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 09:24:38 volumio volumio[20205]: info: Successfully started MPD Monitor Dec 09 09:24:38 volumio volumio[20205]: info: Successfully started MPD Monitor Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=debug msg="completed challenge" Dec 09 09:24:38 volumio go-librespot[20655]: time="2025-12-09T09:24:38-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:39 volumio volumio[20205]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:39 volumio volumio[20205]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 09 09:24:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:41 volumio go-librespot[20676]: go-librespot daemon starting... Dec 09 09:24:41 volumio go-librespot[20677]: time="2025-12-09T09:24:41-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:41 volumio go-librespot[20677]: time="2025-12-09T09:24:41-06:00" level=debug msg="app state loaded" Dec 09 09:24:41 volumio go-librespot[20677]: time="2025-12-09T09:24:41-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:41 volumio go-librespot[20677]: time="2025-12-09T09:24:41-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=info msg="zeroconf server listening on port 38887" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="obtained new client token: AAA3rLoEKdFaL2gz5YkUacpKsWFWDQs/NCKREkxDv/QvnO7+XSwRYyjzR7sEVi6AreJEz0tjYYPFNxAILo7PD1chnLrHpQEbJi/oc47ry0vlvZ/sc690yDqRLvwgUgUQEX2BHSblKgB0i/b6q4Tp0GFChz5A914gJRlszZiJyMBH3JUUIBVZzMpMXOgyPBV3ljZoOMyPpkqp1o8ezogbQJ2q5fJCu9cWZB11kRtJT5s1uIvt/t/lmf0=" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=debug msg="completed challenge" Dec 09 09:24:42 volumio go-librespot[20677]: time="2025-12-09T09:24:42-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:43 volumio volumio[20205]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:43 volumio volumio[20205]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 09 09:24:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:45 volumio go-librespot[20684]: go-librespot daemon starting... Dec 09 09:24:45 volumio go-librespot[20685]: time="2025-12-09T09:24:45-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:45 volumio go-librespot[20685]: time="2025-12-09T09:24:45-06:00" level=debug msg="app state loaded" Dec 09 09:24:45 volumio go-librespot[20685]: time="2025-12-09T09:24:45-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:45 volumio go-librespot[20685]: time="2025-12-09T09:24:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:46 volumio volumio[20205]: info: Initializing connection to go-librespot Websocket Dec 09 09:24:46 volumio go-librespot[20685]: time="2025-12-09T09:24:46-06:00" level=debug msg="new websocket client" Dec 09 09:24:46 volumio volumio[20205]: info: Connection to go-librespot Websocket established Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=info msg="zeroconf server listening on port 41179" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="obtained new client token: AACQIAOBk9pmJlHtavwrG/94y4DVTYJazfPqafDbzg3eLIVWyEGrU0AD98CO5oNgotPzMWSSC1FTeYnfaStRQGK3AlQ49RCWYp9pOjH/g0wjJUknm2GILlX6NOeWemPcu7v7eic26J7uIXPPOiQKR/Iv4dTWwnjpO/dwQVGOPxy5gUdH5gU5QeO0fy+9qd8WqhMTZlK1yTZy33LUQSOF/CkICfbgxo42yvvKvVO94SL141npj5PrD9I=" Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin bluetooth to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin multiroom to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin metavolumio to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin cd_controller to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 09 09:24:47 volumio volumio[20205]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=debug msg="completed challenge" Dec 09 09:24:47 volumio go-librespot[20685]: time="2025-12-09T09:24:47-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:48 volumio volumio[20205]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 09 09:24:48 volumio volumio[20205]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 09 09:24:48 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:48 volumio volumio[20205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:24:48 volumio volumio[20205]: info: Starting MyVolumio Remote Streaming Endpoints Dec 09 09:24:48 volumio volumio[20205]: info: MyVolumio login type: Token Dec 09 09:24:48 volumio volumio[20205]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 09 09:24:48 volumio volumio[20205]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 09 09:24:48 volumio volumio[20205]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 09 09:24:48 volumio volumio[20205]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 09 09:24:48 volumio volumio[20205]: info: Streaming services startup Dec 09 09:24:48 volumio volumio[20205]: info: Starting Streaming Daemon Dec 09 09:24:49 volumio sudo[20707]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 09 09:24:49 volumio sudo[20707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:49 volumio volumio[20205]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 09 09:24:49 volumio sudo[20707]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:49 volumio volumio[20205]: info: Getting Spotify volume Dec 09 09:24:49 volumio volumio[20205]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 09:24:49 volumio volumio[20205]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:24:49 volumio volumio[20205]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 09 09:24:49 volumio volumio[20205]: errno: -111, Dec 09 09:24:49 volumio volumio[20205]: code: 'ECONNREFUSED', Dec 09 09:24:49 volumio volumio[20205]: syscall: 'connect', Dec 09 09:24:49 volumio volumio[20205]: address: '127.0.0.1', Dec 09 09:24:49 volumio volumio[20205]: port: 9879, Dec 09 09:24:49 volumio volumio[20205]: response: undefined Dec 09 09:24:49 volumio volumio[20205]: } Dec 09 09:24:49 volumio volumio[20205]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 09:24:49 volumio sudo[20727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 09:23' Dec 09 09:24:49 volumio sudo[20727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:50 volumio sudo[20727]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:50 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:50] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 09 09:24:50 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:50] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 09 09:24:50 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 09 09:24:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:50 volumio go-librespot[20732]: go-librespot daemon starting... Dec 09 09:24:50 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 09 09:24:50 volumio systemd[1]: volumio.service: Consumed 44.832s CPU time. Dec 09 09:24:50 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="app state loaded" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:50 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 09:24:50 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24270. Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=info msg="zeroconf server listening on port 35919" Dec 09 09:24:50 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 09:24:50 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 09 09:24:50 volumio systemd[1]: volumio.service: Consumed 44.832s CPU time. Dec 09 09:24:50 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 09 09:24:50 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="obtained new client token: AACWcgEULJbSbXv0h4qPtWJBcuWWjuxuqDMRz/IrF470G5fTzxFuE2kaWjSWboP4ZE71hII1Ug6IcM2HmMbM2YkDbVK8I8cpwC0K8qucEd771KKdRcMgXOw5FNNuc15hvIs4D5SP4fVtGGYfGPtAY85EaswVrVoZhUtb5DvxwU5Gm16jkS7+yBAlfz2bbH4DV7/S/QbY9IvpPbOvSuCuBwIr9D9TvEiMnaoViVqH5k7Hzy8BnkMobL6pwg==" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=debug msg="completed challenge" Dec 09 09:24:50 volumio go-librespot[20733]: time="2025-12-09T09:24:50-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:52 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:24:52 volumio volumio[20747]: info: ----- Volumio3 ---- Dec 09 09:24:52 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:24:52 volumio volumio[20747]: info: ----- System startup ---- Dec 09 09:24:52 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:24:53 volumio volumio[20747]: info: MYVOLUMIO Environment detected Dec 09 09:24:53 volumio volumio[20747]: info: Plugin folders cleanup Dec 09 09:24:53 volumio volumio[20747]: info: Scanning into folder /volumio/app/plugins/ Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category audio_interface Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category miscellanea Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category music_service Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category plugins.json Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category system_controller Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category user_interface Dec 09 09:24:53 volumio volumio[20747]: info: Scanning into folder /data/plugins/ Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category audio_interface Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category music_service Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category system_controller Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category system_hardware Dec 09 09:24:53 volumio volumio[20747]: info: Scanning category user_interface Dec 09 09:24:53 volumio volumio[20747]: info: Plugin folders cleanup completed Dec 09 09:24:53 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:24:53 volumio volumio[20747]: info: ----- Core plugins startup ---- Dec 09 09:24:53 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:24:53 volumio volumio[20747]: info: Loading plugins from folder /volumio/app/plugins/ Dec 09 09:24:53 volumio volumio[20747]: info: Adding plugin upnp to MyMusic Plugins Dec 09 09:24:53 volumio volumio[20747]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 09 09:24:53 volumio volumio[20747]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 09 09:24:53 volumio volumio[20747]: info: Loading plugins from folder /data/plugins/ Dec 09 09:24:53 volumio volumio[20747]: info: Loading plugin "system"... Dec 09 09:24:53 volumio volumio[20747]: info: Loading plugin "appearance"... Dec 09 09:24:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 09 09:24:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:54 volumio go-librespot[20775]: go-librespot daemon starting... Dec 09 09:24:54 volumio go-librespot[20776]: time="2025-12-09T09:24:54-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:54 volumio go-librespot[20776]: time="2025-12-09T09:24:54-06:00" level=debug msg="app state loaded" Dec 09 09:24:54 volumio go-librespot[20776]: time="2025-12-09T09:24:54-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:54 volumio go-librespot[20776]: time="2025-12-09T09:24:54-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "network"... Dec 09 09:24:54 volumio volumio[20747]: info: Refreshing Cached IP Addresses Dec 09 09:24:54 volumio sudo[20783]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 09:24:54 volumio sudo[20783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:54 volumio sudo[20785]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 09:24:54 volumio sudo[20785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:54 volumio sudo[20783]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:54 volumio sudo[20785]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "services"... Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "alsa_controller"... Dec 09 09:24:54 volumio sudo[20796]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 09 09:24:54 volumio sudo[20796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:54 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "wizard"... Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "networkfs"... Dec 09 09:24:54 volumio volumio[20747]: info: Starting Udev Watcher for removable devices Dec 09 09:24:54 volumio volumio[20747]: info: Ignoring mount for partition: boot Dec 09 09:24:54 volumio volumio[20747]: info: Ignoring mount for partition: volumio Dec 09 09:24:54 volumio volumio[20747]: info: Ignoring mount for partition: volumio_data Dec 09 09:24:54 volumio volumio[20747]: info: Mounting Device Wikipedia Dec 09 09:24:54 volumio sudo[20822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 09 09:24:54 volumio sudo[20822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:24:54 volumio sudo[20822]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:54 volumio volumio[20747]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 09:24:54 volumio volumio[20747]: dmesg(1) may have more information after failed mount system call. Dec 09 09:24:54 volumio volumio[20747]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 09 09:24:54 volumio volumio[20747]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 09:24:54 volumio volumio[20747]: dmesg(1) may have more information after failed mount system call. Dec 09 09:24:54 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "volumio_command_line_client"... Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "upnp"... Dec 09 09:24:54 volumio volumio[20747]: info: [1765293894994] Starting Upmpd Daemon Dec 09 09:24:54 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 09:24:54 volumio volumio[20747]: info: Loading plugin "my_music"... Dec 09 09:24:55 volumio volumio[20747]: info: Loading plugin "mpd"... Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=info msg="zeroconf server listening on port 35067" Dec 09 09:24:55 volumio volumio-remote-updater[9752]: [2025-12-09 09:24:55] [connect] Successful connection Dec 09 09:24:55 volumio sudo[20796]: pam_unix(sudo:session): session closed for user root Dec 09 09:24:55 volumio volumio[20747]: info: Loading plugin "upnp_browser"... Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="obtained new client token: AACi39TgkpyuKgOdsDZd42aWvOBbyV/MfMyofZBlvpCH46iDFbG5PX9xLv7pYFl3Ipescd67TZq74mU1iS6eU6Bqcx707IrybRpCGXaay2Oxtnjo/CmO8QuzjYXoo9M0VuhBMQz0KKvO/Tkn9ccCdiC7r+vqSoDrRwGYfACx6x4CpxBuc1d7B9gO6RDG9ftbKPoGqyJ/5rr62iefBmmlu46Xc9K3PLWCtLtmiiN2SLt4+Jrw2i9LvLTFyg==" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="completed keyexchange" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=debug msg="completed challenge" Dec 09 09:24:55 volumio go-librespot[20776]: time="2025-12-09T09:24:55-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:24:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:24:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:24:56 volumio volumio[20747]: info: Loading plugin "alarm-clock"... Dec 09 09:24:57 volumio volumio[20747]: info: Loading plugin "airplay_emulation"... Dec 09 09:24:57 volumio volumio[20747]: info: Starting Shairport Sync Dec 09 09:24:57 volumio volumio[20747]: info: Loading plugin "last_100"... Dec 09 09:24:57 volumio volumio[20747]: info: Loading plugin "webradio"... Dec 09 09:24:57 volumio volumio[20747]: info: Loading plugin "i2s_dacs"... Dec 09 09:24:57 volumio volumio[20747]: info: I2S DAC not set, start Auto-detection Dec 09 09:24:57 volumio volumio[20747]: info: Loading plugin "volumiodiscovery"... Dec 09 09:24:57 volumio volumio[20747]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:57 volumio volumio[20747]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:57 volumio volumio[20747]: *** WARNING *** For more information see Dec 09 09:24:57 volumio volumio[20747]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:57 volumio volumio[20747]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:57 volumio volumio[20747]: *** WARNING *** For more information see Dec 09 09:24:57 volumio node[20747]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:57 volumio node[20747]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:57 volumio node[20747]: *** WARNING *** For more information see Dec 09 09:24:57 volumio node[20747]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 09:24:57 volumio node[20747]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 09:24:57 volumio node[20747]: *** WARNING *** For more information see Dec 09 09:24:57 volumio volumio[20747]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 09 09:24:57 volumio volumio[20747]: info: Discovery: Started advertising with name: Volumio Dec 09 09:24:57 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 09:24:57 volumio volumio[20747]: info: Loading plugin "bandcamp"... Dec 09 09:24:58 volumio volumio[20747]: info: Plugin calmradio is not enabled Dec 09 09:24:58 volumio volumio[20747]: info: Loading plugin "soundcloud"... Dec 09 09:24:58 volumio volumio[20747]: info: Loading plugin "spop"... Dec 09 09:24:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 09 09:24:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:24:59 volumio go-librespot[20830]: go-librespot daemon starting... Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="app state loaded" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="stored credentials not found" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=info msg="zeroconf server listening on port 37513" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="obtained new client token: AACUpKvdZvTwfBKMhxt4ciiCyZDONGwsn0jeVuvVlYqvbJ7Kw7vMk4xbG2pN6IXNaNFihKw0g75WksWzl54pDQoWk4MaEyS3mzgOCkQsMiGLyuX0+KUuJr96P5Q/OiW7xDVuTKc0k6Eetv50s4IYMrVSCoa/k5W7F9UqKQwK16bacXb5LoZe6SSF45V5FbxbGKfTLCShX9FiITFSJwl2HsnfVspzYI7DQL/dF+aPIxSV2tPLOUt6kBJloQ==" Dec 09 09:24:59 volumio go-librespot[20831]: time="2025-12-09T09:24:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:24:59 volumio volumio[20747]: info: Loading plugin "squeezelite_mc"... Dec 09 09:25:00 volumio volumio[20747]: info: Loading plugin "youtube2"... Dec 09 09:25:01 volumio volumio[20747]: info: Loading plugin "ytcr"... Dec 09 09:25:02 volumio volumio[20747]: info: Loading plugin "ytmusic"... Dec 09 09:25:03 volumio volumio[20747]: info: Plugin now_playing is not enabled Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "outputs"... Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "albumart"... Dec 09 09:25:03 volumio volumio[20747]: info: Plugin example_plugin is not enabled Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "inputs"... Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "updater_comm"... Dec 09 09:25:03 volumio volumio[20747]: info: Plugin mpdemulation is not enabled Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "rest_api"... Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "websocket"... Dec 09 09:25:03 volumio volumio[20747]: info: Starting Socket.io Server version 1.7.4 Dec 09 09:25:03 volumio volumio[20747]: info: Plugin fusiondsp is not enabled Dec 09 09:25:03 volumio volumio[20747]: info: Plugin mpdoutput is not enabled Dec 09 09:25:03 volumio volumio[20747]: info: Plugin RoonBridge is not enabled Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "podcast"... Dec 09 09:25:03 volumio volumio[20747]: info: ControllerPodcast::constructor Dec 09 09:25:03 volumio volumio[20747]: info: Loading plugin "volusonic"... Dec 09 09:25:03 volumio volumio[20839]: Forking 3 albumart workers Dec 09 09:25:05 volumio volumio[20850]: Starting albumart workers Dec 09 09:25:05 volumio volumio[20747]: info: Applying required configuration parameters for plugin volusonic Dec 09 09:25:05 volumio volumio[20747]: info: Loading plugin "backup_restore"... Dec 09 09:25:05 volumio volumio[20849]: Starting albumart workers Dec 09 09:25:05 volumio volumio[20851]: Starting albumart workers Dec 09 09:25:05 volumio volumio[20747]: info: Applying required configuration parameters for plugin backup_restore Dec 09 09:25:05 volumio volumio[20747]: info: Plugin rpi_eeprom_config is not enabled Dec 09 09:25:05 volumio volumio[20747]: info: Plugin rpi_eeprom_updater is not enabled Dec 09 09:25:05 volumio volumio[20747]: info: Loading plugin "scheduledrestart"... Dec 09 09:25:05 volumio volumio[20747]: info: Applying required configuration parameters for plugin scheduledrestart Dec 09 09:25:05 volumio volumio[20747]: info: Plugin Bluetoothremote is not enabled Dec 09 09:25:05 volumio volumio[20747]: info: Plugin music_services_shield is not enabled Dec 09 09:25:05 volumio volumio[20747]: info: Loading plugin "Systeminfo"... Dec 09 09:25:06 volumio volumio[20747]: info: Plugin peppymeterbasic is not enabled Dec 09 09:25:06 volumio volumio[20747]: info: Loading plugin "peppyspectrum"... Dec 09 09:25:06 volumio volumio[20747]: info: Loading i18n strings for locale en Dec 09 09:25:06 volumio volumio[20747]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 09:25:06 volumio volumio[20747]: Updating browse sources language Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::initPlayerControls Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:25:06 volumio volumio[20747]: Express server listening on port 3000 Dec 09 09:25:06 volumio volumio[20747]: [Metrics] WebUI: 14s 393.10ms Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::resetVolumioState Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::getcurrentVolume Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:06 volumio sudo[20916]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 09:25:06 volumio sudo[20916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:06 volumio sudo[20916]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:06 volumio sudo[20918]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 09:25:06 volumio sudo[20918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:06 volumio sudo[20918]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:06 volumio volumio[20747]: info: Volumio Network Manager: Network status updated: 1 Dec 09 09:25:06 volumio volumio[20747]: info: VolumeController:: Volume=86 Mute =false Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::pushState Dec 09 09:25:06 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::volumioPushState Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::updateTrackBlock Dec 09 09:25:06 volumio volumio[20747]: info: CorePlayQueue::getTrackBlock Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 09:25:06 volumio volumio[20747]: info: Reloading queue from file Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::setRepeat null single undefined Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::pushState Dec 09 09:25:06 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::volumioPushState Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::setRandom null Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::pushState Dec 09 09:25:06 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::volumioPushState Dec 09 09:25:06 volumio volumio[20747]: info: Setting Device type: Raspberry PI Dec 09 09:25:06 volumio volumio[20747]: info: VolumeController:: Volume=86 Mute =false Dec 09 09:25:06 volumio sudo[20931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 09 09:25:06 volumio volumio[20747]: info: CoreStateMachine::pushState Dec 09 09:25:06 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:06 volumio volumio[20747]: info: CoreCommandRouter::volumioPushState Dec 09 09:25:06 volumio sudo[20931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:06 volumio volumio[20747]: info: Completed loading Core Plugins Dec 09 09:25:06 volumio volumio[20747]: info: Preparing to generate the ALSA configuration file Dec 09 09:25:06 volumio volumio[20747]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 09:25:07 volumio volumio[20747]: info: Reading ALSA contributions from plugins. Dec 09 09:25:07 volumio volumio[20747]: info: Asound.conf file unchanged, so no further update is needed Dec 09 09:25:07 volumio volumio[20747]: info: Output device has changed, restarting MPD Dec 09 09:25:07 volumio sudo[20931]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:07 volumio volumio[20747]: info: Output device has changed, restarting Shairport Sync Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:07 volumio sudo[20935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 09:25:07 volumio sudo[20935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:07 volumio sudo[20935]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:07 volumio sudo[20937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 09:25:07 volumio sudo[20937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:07 volumio volumio[20747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:25:07 volumio volumio[20747]: info: ___________ START PLUGINS ___________ Dec 09 09:25:07 volumio volumio[20747]: info: ControllerMpd::onStart: Initializing MPD Dec 09 09:25:07 volumio volumio[20747]: info: Creating MPD Configuration file Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907100] CoreMusicLibrary::Adding element Media Servers Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 09 09:25:07 volumio sudo[20945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:07 volumio sudo[20945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:07 volumio sudo[20947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 09:25:07 volumio sudo[20947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:07 volumio sudo[20945]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:07 volumio volumio[20747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:07 volumio volumio[20747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 09:25:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907225] CoreMusicLibrary::Adding element Last_100 Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio systemd[1]: mpd.service: Consumed 4.508s CPU time. Dec 09 09:25:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 09:25:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 09:25:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907237] CoreMusicLibrary::Adding element Webradio Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 09:25:07 volumio volumio[20747]: info: Initializing BBC Radios Dec 09 09:25:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907318] CoreMusicLibrary::Adding element Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907330] CoreMusicLibrary::Adding element SoundCloud Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: info: Creating Spotify config file Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:07 volumio sudo[20972]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 09:25:07 volumio sudo[20972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 09:25:07 volumio sudo[20972]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:07 volumio volumio[20747]: info: [squeezelite_mc] Starting proxy server... Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907684] CoreMusicLibrary::Adding element YouTube2 Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907702] CoreMusicLibrary::Adding element YouTube Music Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube Music Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907714] CoreMusicLibrary::Adding element Podcast Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube Music Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Podcast Dec 09 09:25:07 volumio volumio[20747]: info: Loading i18n strings for locale en Dec 09 09:25:07 volumio volumio[20747]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 09:25:07 volumio volumio[20747]: Updating browse sources language Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube Music Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Podcast Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube Music Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Podcast Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:07 volumio volumio[20747]: info: [1765293907762] CoreMusicLibrary::Adding element Volusonic Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source YouTube Music Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Podcast Dec 09 09:25:07 volumio volumio[20747]: Cannot find translation for source Volusonic Dec 09 09:25:07 volumio volumio[20747]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 09 09:25:07 volumio volumio[20747]: info: Volumio Calling Home Dec 09 09:25:07 volumio volumio-remote-updater[9752]: [2025-12-09 09:25:07] [connect] Successful connection Dec 09 09:25:07 volumio volumio[20747]: info: [squeezelite_mc] Proxy server started on port 43477 Dec 09 09:25:07 volumio volumio[20747]: info: Preparing to generate the ALSA configuration file Dec 09 09:25:07 volumio volumio[20747]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 09:25:08 volumio volumio[20747]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 09:25:08 volumio volumio[20747]: info: Discovery: Found device Volumio Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::volumioGetState Dec 09 09:25:08 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:08 volumio volumio[20747]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 09:25:08 volumio volumio[20747]: info: Discovery: Found device Volumio Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::volumioGetState Dec 09 09:25:08 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:08 volumio volumio[20747]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 09:25:08 volumio volumio[20747]: info: Reading ALSA contributions from plugins. Dec 09 09:25:08 volumio volumio[20747]: info: MPD Permissions set Dec 09 09:25:08 volumio volumio[20747]: info: MPD Permissions set Dec 09 09:25:08 volumio volumio[20747]: info: Upmpdcli Daemon Started Dec 09 09:25:08 volumio volumio-remote-updater[9752]: [2025-12-09 09:25:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765293907 101 Dec 09 09:25:08 volumio volumio[20747]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 09 09:25:08 volumio volumio[20747]: info: Spotify config file written Dec 09 09:25:08 volumio sudo[20982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 09 09:25:08 volumio sudo[20982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 09 09:25:08 volumio volumio[20747]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 09 09:25:08 volumio systemd[1]: go-librespot-daemon.service: Killing process 20834 (go-librespot) with signal SIGKILL. Dec 09 09:25:08 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 09 09:25:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:08 volumio volumio[20747]: info: VolumeController:: Volume=86 Mute =false Dec 09 09:25:08 volumio volumio[20747]: info: CoreStateMachine::pushState Dec 09 09:25:08 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::volumioPushState Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Server discovery started Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Player finder started Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio go-librespot[20984]: go-librespot daemon starting... Dec 09 09:25:08 volumio sudo[20982]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=debug msg="app state loaded" Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=debug msg="stored credentials not found" Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio volumio[20747]: info: No need to fix Spotify hosts Dec 09 09:25:08 volumio volumio[20747]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 09 09:25:08 volumio volumio[20747]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 09:25:08 volumio volumio[20747]: SPOTIFY: BQAdemof-O9v2SKZEzcxJE7HhSigAJODG8vSQesTmZwkyGy638QdFO7E_wqXz5Yl5ABWrcNADNGqfuambtMjv1vth0e5GXLox_6bJ58_nfTMsRlAH84EdfBUA_welGmy8LIvbvwbn0vnJMKCBXbrEDb0KpEJI_ktm5uv4Qwc6sE4XpQMMVQbK0ST7RvxIjibl0uid-xQ11iwgxE6aZWLN4cznLcMURR9veVkSRA Dec 09 09:25:08 volumio volumio[20747]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 09:25:08 volumio volumio[20747]: info: New Spotify access token = BQAdemof-O9v2SKZEzcxJE7HhSigAJODG8vSQesTmZwkyGy638QdFO7E_wqXz5Yl5ABWrcNADNGqfuambtMjv1vth0e5GXLox_6bJ58_nfTMsRlAH84EdfBUA_welGmy8LIvbvwbn0vnJMKCBXbrEDb0KpEJI_ktm5uv4Qwc6sE4XpQMMVQbK0ST7RvxIjibl0uid-xQ11iwgxE6aZWLN4cznLcMURR9veVkSRA Dec 09 09:25:08 volumio volumio[20747]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 09 09:25:08 volumio volumio[20747]: info: Volumio called home Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:25:08 volumio volumio[20747]: info: Starting Shairport Sync Dec 09 09:25:08 volumio go-librespot[20989]: time="2025-12-09T09:25:08-06:00" level=info msg="zeroconf server listening on port 32795" Dec 09 09:25:08 volumio volumio[20747]: info: Starting Shairport Sync Dec 09 09:25:08 volumio volumio[20747]: info: Starting Shairport Sync Dec 09 09:25:08 volumio sudo[21005]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 09:25:08 volumio sudo[21005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio sudo[21009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:25:08 volumio sudo[21009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio sudo[21013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:25:08 volumio sudo[21013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio sudo[21011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:25:08 volumio sudo[21011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio sudo[21005]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:08 volumio volumio[20747]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 09 09:25:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 09:25:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 09:25:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:25:08 volumio systemd[1]: shairport-sync.service: Consumed 1.849s CPU time. Dec 09 09:25:08 volumio volumio[20747]: info: Asound.conf file unchanged, so no further update is needed Dec 09 09:25:08 volumio volumio[20747]: info: Output device has changed, restarting MPD Dec 09 09:25:08 volumio sudo[21020]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 09 09:25:08 volumio sudo[21020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio volumio[20747]: info: Output device has changed, restarting Shairport Sync Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:25:08 volumio sudo[21023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 09:25:08 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:08 volumio sudo[21023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio sudo[21011]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:08 volumio sudo[21023]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:08 volumio sudo[21025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 09:25:08 volumio sudo[21025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:08 volumio sudo[21009]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:08 volumio sudo[21013]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:08 volumio sudo[21020]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:09 volumio volumio[20747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 09:25:09 volumio go-librespot[20989]: time="2025-12-09T09:25:09-06:00" level=debug msg="obtained new client token: AACKyrpS1jsnAtdg2EuBrbWiE7CLGAp4YfzzEOf+y+vtIx+f4UJI6Le33x9NClhEM9BVXQ69VQ+U45jI/wiqBxYyRUBCxoJDMCDdDiR1OsAavXhHb5VYGDKuEmCUIRZxLWzbVq5/uxAq0GYt5Jbx3dMM1TxOdMbkaauSzL8FY2UnEDzIb9Quu8uLtIiCUWBmApyBvf5lyAAB5B/5Wh+jAgmnDP7NOukzEx2MWxEWP5gKHgd7hMKQz5M=" Dec 09 09:25:09 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 09 09:25:09 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 09:25:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 09:25:09 volumio systemd[1]: mpd.service: Consumed 1.592s CPU time. Dec 09 09:25:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 09:25:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 09:25:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 09:25:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 09:25:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 09:25:09 volumio go-librespot[20989]: time="2025-12-09T09:25:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:25:09 volumio volumio[20747]: info: MPD Permissions set Dec 09 09:25:09 volumio volumio[20747]: info: Shairport-Sync Started Dec 09 09:25:09 volumio volumio[20747]: Error adding Membership: Error: addMembership EINVAL Dec 09 09:25:09 volumio volumio[20747]: info: Shairport-Sync Started Dec 09 09:25:09 volumio volumio[20747]: info: Shairport-Sync Started Dec 09 09:25:09 volumio volumio[20747]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 09:25:09 volumio go-librespot[20989]: time="2025-12-09T09:25:09-06:00" level=debug msg="completed keyexchange" Dec 09 09:25:09 volumio go-librespot[20989]: time="2025-12-09T09:25:09-06:00" level=debug msg="completed challenge" Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio sudo[21056]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 09:25:09 volumio sudo[21056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio sudo[21056]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:09 volumio go-librespot[20989]: time="2025-12-09T09:25:09-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:25:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:25:09 volumio sudo[21069]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 09:25:09 volumio sudo[21069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:09 volumio sudo[21069]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::volumioGetState Dec 09 09:25:09 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:09 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 09 09:25:09 volumio volumio[20747]: info: Starting Shairport Sync Dec 09 09:25:09 volumio sudo[21081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 09 09:25:09 volumio sudo[21081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:09 volumio sudo[21084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 09:25:09 volumio sudo[21084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:09 volumio volumio[20747]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 09 09:25:09 volumio volumio[20747]: info: Spotify Successfully logged in Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 09:25:09 volumio volumio[20747]: info: [1765293909868] CoreMusicLibrary::Adding element Spotify Dec 09 09:25:09 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source Bandcamp Discover Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source SoundCloud Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source YouTube2 Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source YouTube Music Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source Podcast Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source Volusonic Dec 09 09:25:09 volumio volumio[20747]: Cannot find translation for source Spotify Dec 09 09:25:09 volumio systemd[1]: Reloading. Dec 09 09:25:09 volumio volumio[20747]: info: [squeezelite_mc] Notification listener started Dec 09 09:25:09 volumio volumio[20747]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 09:25:10 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:10 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:10 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 09:25:10 volumio volumio[20747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 09:25:10 volumio volumio[20747]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 09:25:10 volumio volumio[20747]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 09:25:11 volumio volumio[20747]: info: go-librespot daemon successfully initialized Dec 09 09:25:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:25:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 09:25:12 volumio sudo[21081]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:12 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 09:25:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 09:25:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:25:12 volumio systemd[1]: shairport-sync.service: Consumed 1.402s CPU time. Dec 09 09:25:12 volumio volumio[20747]: info: CoreCommandRouter::volumioGetState Dec 09 09:25:12 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:12 volumio sudo[21111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:12 volumio sudo[21111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 09:25:12 volumio sudo[21084]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:12 volumio volumio[20747]: info: Shairport-Sync Started Dec 09 09:25:12 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 09 09:25:12 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 09 09:25:12 volumio systemd[1]: setdatetime-helper.service: Consumed 1.234s CPU time. Dec 09 09:25:12 volumio sudo[21111]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:12 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 09 09:25:12 volumio sudo[21131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 09 09:25:12 volumio sudo[21131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:12 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 09:25:12 volumio volumio[20747]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 09 09:25:12 volumio volumio[20747]: info: CoreCommandRouter::volumioGetState Dec 09 09:25:12 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:12 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 09 09:25:12 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 09:25:12 volumio sudo[21131]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 09 09:25:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:12 volumio go-librespot[21134]: go-librespot daemon starting... Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=debug msg="app state loaded" Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=debug msg="stored credentials not found" Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:25:12 volumio go-librespot[21135]: time="2025-12-09T09:25:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:25:13 volumio go-librespot[21135]: time="2025-12-09T09:25:13-06:00" level=info msg="zeroconf server listening on port 44289" Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:13 volumio sudo[21143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:13 volumio sudo[21143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:13 volumio sudo[21143]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 09 09:25:13 volumio sudo[21147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 09 09:25:13 volumio sudo[21147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:13 volumio sudo[21147]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 09 09:25:13 volumio sudo[21150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 09 09:25:13 volumio sudo[21150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:13 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 09:25:13 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 09:25:13 volumio sudo[21150]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:13 volumio go-librespot[21135]: time="2025-12-09T09:25:13-06:00" level=debug msg="obtained new client token: AAA4YMpoyXsYyk2d7AU1hSzd3Kge5DovbKv2Q4z9W5L/TYfGXSvqcyPSIVqUaBBaDTX9DTZVTkQpdoyhEJd22GeuXUAK0UN3HvN3xscqBFMr27iaPxeIDreVnRqaIepHaP2x98u8ItamTwsn4HOgDJsI7u4nGuXbNtI0PSm3tunIIIoJXOQF7wMIqg7PZY9LJb5nGsfK1EWSxmVznHmReEyo+Qow+xmcWhfqnck8O87FvdhNgglVUFHPQA==" Dec 09 09:25:13 volumio mpd[21076]: 2025-12-09T09:25:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 09:25:13 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 09 09:25:13 volumio sudo[20937]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:13 volumio sudo[21025]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:13 volumio sudo[20947]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:13 volumio volumio[20747]: error: MPD error: The expression evaluated to a falsy value: Dec 09 09:25:13 volumio volumio[20747]: assert.ok(self.idling) Dec 09 09:25:13 volumio volumio[20747]: error: The expression evaluated to a falsy value: Dec 09 09:25:13 volumio volumio[20747]: assert.ok(self.idling) Dec 09 09:25:13 volumio go-librespot[21135]: time="2025-12-09T09:25:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:25:13 volumio volumio[20747]: error: MPD error: The expression evaluated to a falsy value: Dec 09 09:25:13 volumio volumio[20747]: assert.ok(self.idling) Dec 09 09:25:13 volumio volumio[20747]: error: The expression evaluated to a falsy value: Dec 09 09:25:13 volumio volumio[20747]: assert.ok(self.idling) Dec 09 09:25:13 volumio volumio[20747]: info: MPD running with PID21076 Dec 09 09:25:13 volumio volumio[20747]: ,establishing connection Dec 09 09:25:13 volumio volumio[20747]: error: updateQueue error: null Dec 09 09:25:13 volumio volumio[20747]: error: updateQueue error: null Dec 09 09:25:13 volumio go-librespot[21135]: time="2025-12-09T09:25:13-06:00" level=debug msg="completed keyexchange" Dec 09 09:25:13 volumio go-librespot[21135]: time="2025-12-09T09:25:13-06:00" level=debug msg="completed challenge" Dec 09 09:25:13 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:13 volumio go-librespot[21135]: time="2025-12-09T09:25:13-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:25:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:25:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:25:14 volumio sudo[21161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:14 volumio sudo[21161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:14 volumio sudo[21161]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:14 volumio volumio[20747]: info: Initializing connection to go-librespot Websocket Dec 09 09:25:14 volumio volumio[20747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 09:25:14 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:14 volumio sudo[21164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:14 volumio sudo[21164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:14 volumio sudo[21164]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:14 volumio volumio[20747]: info: CoreCommandRouter::volumioGetState Dec 09 09:25:14 volumio volumio[20747]: info: CorePlayQueue::getTrack 0 Dec 09 09:25:15 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:15 volumio sudo[21181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:15 volumio sudo[21181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:15 volumio sudo[21181]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:15 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:15 volumio sudo[21184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:15 volumio sudo[21184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:15 volumio sudo[21184]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:16 volumio volumio[20747]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 09:25:16 volumio sudo[21187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 09:25:16 volumio sudo[21187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:16 volumio sudo[21187]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:16 volumio volumio[20747]: info: Completed starting Core Plugins Dec 09 09:25:16 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:25:16 volumio volumio[20747]: info: ----- MyVolumio plugins startup ---- Dec 09 09:25:16 volumio volumio[20747]: info: ------------------------------------------- Dec 09 09:25:16 volumio volumio[20747]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 09 09:25:16 volumio sudo[21190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 09:25:16 volumio sudo[21190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:16 volumio sudo[21192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 09:25:16 volumio sudo[21192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:16 volumio sudo[21195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 09:25:16 volumio sudo[21195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 09:25:16 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 09:25:16 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 09:25:16 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 09:25:16 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 09:25:16 volumio sudo[21190]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:16 volumio sudo[21192]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:16 volumio mpd_monitor.sh[21198]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 09:25:16 volumio sudo[21195]: pam_unix(sudo:session): session closed for user root Dec 09 09:25:16 volumio volumio[20747]: info: Successfully started MPD Monitor Dec 09 09:25:16 volumio volumio[20747]: info: Successfully started MPD Monitor Dec 09 09:25:16 volumio volumio[20747]: info: Successfully started MPD Monitor Dec 09 09:25:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 09 09:25:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:17 volumio go-librespot[21202]: go-librespot daemon starting... Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="app state loaded" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="stored credentials not found" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:25:17 volumio volumio[20747]: info: Initializing connection to go-librespot Websocket Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="new websocket client" Dec 09 09:25:17 volumio volumio[20747]: info: Connection to go-librespot Websocket established Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=info msg="zeroconf server listening on port 46163" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="obtained new client token: AABU1CsC/tz3lIZEdV9vhqaboJOHkwkHyYMSgwNjdL9jR6gvHSK8fElSbcIKD5Z9/HCNovJIngEIhead1Q1xRgK7pQNKAnssES+gJGBOilvRVDU9DIBp8akssWzaTKY6KCtqk+SP0bzK6/ZWWOjc7mF8s7koagdWYcyNWp7vJs3WbMq8tPvXRXDEIfKTarL24VpuFhL4Lc5Tl4wuRpAcrelKhzmNHWhaypvPpre4/H2eivDNGNVYzRNfKg==" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="completed keyexchange" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=debug msg="completed challenge" Dec 09 09:25:17 volumio go-librespot[21203]: time="2025-12-09T09:25:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:25:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:25:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:25:17 volumio volumio[20747]: info: Connection to go-librespot Websocket closed Dec 09 09:25:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 09 09:25:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 09:25:21 volumio go-librespot[21210]: go-librespot daemon starting... Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="app state loaded" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="stored credentials not found" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=info msg="zeroconf server listening on port 35231" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="obtained new client token: AABG2KikhnUChwmDFK3JG6Wj2+3RtmmLLWXIZfAmJDYn1SkxuA4uGOe0RLUn/yzhfBNZGJulY88WMHPw56LEBr4b+ssVBFxvsZ7W4MaWkkhYGqq2Z09F8g0mlUQMx+fwsnnAj5jJnF/BeRzelus2eU2VkqEVTWoOyX5rHjYH1uqAPYDnFX3KIyHSWG/LzKWqI1QfT7/BExovAcNn0vLbnZqELNIw+xURuTzDa36QXgjYBjKkTd+O73SYVg==" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="completed keyexchange" Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="completed challenge" Dec 09 09:25:21 volumio volumio[20747]: info: Getting Spotify volume Dec 09 09:25:21 volumio volumio[20747]: info: Initializing connection to go-librespot Websocket Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=debug msg="new websocket client" Dec 09 09:25:21 volumio volumio[20747]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 09 09:25:21 volumio volumio[20747]: info: Connection to go-librespot Websocket established Dec 09 09:25:21 volumio go-librespot[21211]: time="2025-12-09T09:25:21-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 09:25:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 09:25:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 09:25:21 volumio volumio[20747]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 09:25:21 volumio volumio[20747]: Error: socket hang up Dec 09 09:25:21 volumio volumio[20747]: at connResetException (node:internal/errors:720:14) Dec 09 09:25:21 volumio volumio[20747]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 09 09:25:21 volumio volumio[20747]: at Socket.emit (node:events:526:35) Dec 09 09:25:21 volumio volumio[20747]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 09 09:25:21 volumio volumio[20747]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 09 09:25:21 volumio volumio[20747]: code: 'ECONNRESET', Dec 09 09:25:21 volumio volumio[20747]: response: undefined Dec 09 09:25:21 volumio volumio[20747]: } Dec 09 09:25:21 volumio volumio[20747]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 09:25:22 volumio sudo[21233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 09:24' Dec 09 09:25:22 volumio sudo[21233]: 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"