Dec 06 12:04:00 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:00 volumio volumio[32717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57.
Dec 06 12:04:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:02 volumio go-librespot[730]: go-librespot daemon starting...
Dec 06 12:04:02 volumio go-librespot[731]: time="2025-12-06T12:04:02-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:02 volumio go-librespot[731]: time="2025-12-06T12:04:02-06:00" level=debug msg="app state loaded"
Dec 06 12:04:02 volumio go-librespot[731]: time="2025-12-06T12:04:02-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:02 volumio go-librespot[731]: time="2025-12-06T12:04:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-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 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-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 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-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 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-06:00" level=info msg="zeroconf server listening on port 37639"
Dec 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-06:00" level=debug msg="obtained new client token: AACWp3SpZ766upvq462HReoE8Zo/VZkKZ5IfjvX6Khkb4KxYdauQ4vuBEiIRpfKoCrtK4lwjan3z2uatCIq6w48r8eMfy20uf8yXXkdNivJ77rI3Q8BBaO+Xt3nCOsh5LED1EGd3MR2QECfGfUIzxyRXlhPHLbpCttoMs8uM3OaWeQr0AaalBjbpt2IL84Tu1i/QXoF8uXNkga/Hnn07gQjm17oY48PaenlzmoWVWVUV/UtE776NPHw="
Dec 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-06:00" level=debug msg="completed challenge"
Dec 06 12:04:03 volumio go-librespot[731]: time="2025-12-06T12:04:03-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 06 12:04:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:04 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:04 volumio volumio[32717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58.
Dec 06 12:04:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:06 volumio go-librespot[739]: go-librespot daemon starting...
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=debug msg="app state loaded"
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-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 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-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 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-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 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=info msg="zeroconf server listening on port 44501"
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=debug msg="obtained new client token: AAAnBXDRhzPyof3BpSsIfRVE3UaClMgM2fq9X1FgvKwMeaxv0S4dY22N4NNrKpjqVo3i7GRfrkroDWjDKROZnULIxPlm73hEZNXh/qqITwI6sl3JxJ4pI7E/rpJ3W2BiXK0hm7nUls+u71MjrWPmwvfaC/DaTqpGufplyH/lND3nZRTklezkh8VG8itA/00sR+awKX06JzfLIY/rmQ5qkpszeCF7exs6LFn0kmlyJ9D+VOvIz+tBUrgHlw=="
Dec 06 12:04:06 volumio go-librespot[740]: time="2025-12-06T12:04:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:07 volumio go-librespot[740]: time="2025-12-06T12:04:07-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:07 volumio go-librespot[740]: time="2025-12-06T12:04:07-06:00" level=debug msg="completed challenge"
Dec 06 12:04:07 volumio go-librespot[740]: time="2025-12-06T12:04:07-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 06 12:04:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:07 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin multiroom to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 06 12:04:07 volumio volumio[32717]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 06 12:04:08 volumio volumio[32717]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 06 12:04:08 volumio volumio[32717]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 06 12:04:08 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:08 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:08 volumio volumio[32717]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 06 12:04:08 volumio volumio[32717]: info: MyVolumio login type: Token
Dec 06 12:04:08 volumio volumio[32717]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 06 12:04:08 volumio volumio[32717]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 06 12:04:09 volumio volumio[32717]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 06 12:04:09 volumio volumio[32717]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 06 12:04:09 volumio volumio[32717]: info: Streaming services startup
Dec 06 12:04:09 volumio volumio[32717]: info: Starting Streaming Daemon
Dec 06 12:04:09 volumio sudo[763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 12:04:09 volumio sudo[763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:09 volumio volumio[32717]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 06 12:04:09 volumio sudo[763]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:09 volumio volumio[32717]: error: Cannot start Volumio Streaming Daemon
Dec 06 12:04:09 volumio volumio[32717]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 12:04:09 volumio volumio[32717]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 12:04:09 volumio volumio[32717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:09 volumio volumio[32717]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 06 12:04:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59.
Dec 06 12:04:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:10 volumio go-librespot[769]: go-librespot daemon starting...
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=debug msg="app state loaded"
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:10 volumio volumio[32717]: info: MyVolumio token set successfully
Dec 06 12:04:10 volumio volumio[32717]: info: MYVOLUMIO: Adding device
Dec 06 12:04:10 volumio volumio[32717]: info: MYVOLUMIO: Evaluating Server
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-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 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-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 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-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 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=info msg="zeroconf server listening on port 43091"
Dec 06 12:04:10 volumio volumio[32717]: info: MyVolumio status changed
Dec 06 12:04:10 volumio volumio[32717]: info: Streaming services startup
Dec 06 12:04:10 volumio volumio[32717]: info: Starting Streaming Daemon
Dec 06 12:04:10 volumio volumio[32717]: info: Removing browser output: myVolumio user plan is not superstar
Dec 06 12:04:10 volumio volumio[32717]: info: Removing audio output:
Dec 06 12:04:10 volumio volumio[32717]: info: Stoppping Tunnel 1
Dec 06 12:04:10 volumio sudo[804]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 12:04:10 volumio sudo[804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=debug msg="obtained new client token: AADUoNysAx+e2zxoBw1xsBBsrWHLGIVo07VHmDddghZmKnXq1A0xS07vJVzGqAgihnG57wVQMdKkHrZJLztffP3UXaHylFCONMCsVZliQEvkVoUf9+JXiPwucMhmWa6TXxYIjRz+s+pgOJxJimG/K0CKrmxqkiG/m1bFGRgBIKqtrOih/AGAwcgv5MrdGUOBHeIYgL4SYMwGxLNzv8Q9Pe1mTCSfDSQlb1N5pqPnx5EPlMZ1uAvNRT9/wg=="
Dec 06 12:04:10 volumio sudo[806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Dec 06 12:04:10 volumio sudo[806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:10 volumio sudo[804]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:10 volumio volumio[32717]: error: Cannot start Volumio Streaming Daemon
Dec 06 12:04:10 volumio volumio[32717]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 12:04:10 volumio volumio[32717]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:04:10 volumio sudo[806]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:10 volumio volumio[32717]: info: Remote SSH Stopped
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-06:00" level=debug msg="completed challenge"
Dec 06 12:04:10 volumio go-librespot[772]: time="2025-12-06T12:04:10-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 06 12:04:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:10 volumio volumio[32717]: info: Setting Geolocation for MyVolumio to us4
Dec 06 12:04:10 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:10 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:10 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:11 volumio volumio[32717]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Dec 06 12:04:11 volumio volumio[32717]: info: Updating MyVolumio device info
Dec 06 12:04:11 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:11 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:11 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:12 volumio volumio[32717]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Dec 06 12:04:12 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:12 volumio volumio[32717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60.
Dec 06 12:04:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:13 volumio go-librespot[809]: go-librespot daemon starting...
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=debug msg="app state loaded"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-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 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-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 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-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 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=info msg="zeroconf server listening on port 39655"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=debug msg="obtained new client token: AAAM+whuQDO9uEcJN7B3pJ5WUdmP6620lu3DBG5va0Dbm+pXtgYaVUDbeuFYDe/Eh3ORCkRmu+p+PwgFoJaQyxBAXywZI9nM1SUh7ZFlyWnZIiWmqPKt+vDmYrMcpM2MiSZDomesmr6RdH6WpfmK8ljfwQI+ioMEiNljpy15svS7ZhxXfcwOewDAMTqL2wcYiXYhst2+CPpc84kJ06B5hQHO632bOgwOEcSvHqvZ0OjANBXSK7Ez5wEx7w=="
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-06:00" level=debug msg="completed challenge"
Dec 06 12:04:14 volumio go-librespot[810]: time="2025-12-06T12:04:14-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 06 12:04:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:15 volumio volumio[32717]: info: MYVOLUMIO: Adding device
Dec 06 12:04:15 volumio volumio[32717]: info: MYVOLUMIO: Evaluating Server
Dec 06 12:04:15 volumio volumio[32717]: info: Setting Geolocation for MyVolumio to us4
Dec 06 12:04:15 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:15 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:15 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:15 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:15 volumio volumio[32717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:15 volumio volumio[32717]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Dec 06 12:04:16 volumio volumio[32717]: info: Updating MyVolumio device info
Dec 06 12:04:16 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:16 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:16 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:16 volumio volumio[32717]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Dec 06 12:04:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61.
Dec 06 12:04:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:17 volumio go-librespot[836]: go-librespot daemon starting...
Dec 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04:17-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04:17-06:00" level=debug msg="app state loaded"
Dec 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04:17-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04: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 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04: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 06 12:04:17 volumio go-librespot[837]: time="2025-12-06T12:04: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 06 12:04:18 volumio go-librespot[837]: time="2025-12-06T12:04:18-06:00" level=info msg="zeroconf server listening on port 32923"
Dec 06 12:04:18 volumio go-librespot[837]: time="2025-12-06T12:04:18-06:00" level=debug msg="obtained new client token: AADNIubAbi+0lcPpXc5MBdwgFIuFIiK/KWAPYnBnOTIxIXrzvvG0VWVkEuCUXam7aNtwgGv1zQBY3V9PNmJ5NNb07w8rJ6rwkqnUuLdl89fEi0pXkRGU+P2fKCixxP3ys0eJOpPKqDwDVVW6OAY4qa0b8JoUugChqw0P9LvrGYcnpRqC6V1epsltVp6CQ8eA9O9fWLgynZnwXgShK2TyHBHpfC4LOu8Vzv+bm1HzyCkW+7oP7fRcelQ="
Dec 06 12:04:18 volumio go-librespot[837]: time="2025-12-06T12:04:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:18 volumio go-librespot[837]: time="2025-12-06T12:04:18-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:18 volumio go-librespot[837]: time="2025-12-06T12:04:18-06:00" level=debug msg="completed challenge"
Dec 06 12:04:18 volumio go-librespot[837]: time="2025-12-06T12:04:18-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 06 12:04:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:18 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:18 volumio volumio[32717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:20 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:04:20 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:20 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 06 12:04:20 volumio volumio-remote-updater[2353]: Test mode disabled
Dec 06 12:04:20 volumio volumio-remote-updater[2353]: Alpha mode disabled
Dec 06 12:04:20 volumio volumio-remote-updater[2353]: Alpha legacy test mode disabled
Dec 06 12:04:20 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 06 12:04:21 volumio volumio[32717]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"ANNOUNCEMENT
\n\n- Production line
\n
\nFIX
\n\n- Nodejs 20.5.1 version pinning with static package fallback
\n
\n","title":"Update v4.073","updateavailable":true}
Dec 06 12:04:21 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 06 12:04:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62.
Dec 06 12:04:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:21 volumio go-librespot[867]: go-librespot daemon starting...
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=debug msg="app state loaded"
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:21 volumio volumio[32717]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=debug msg="new websocket client"
Dec 06 12:04:21 volumio volumio[32717]: info: Connection to go-librespot Websocket established
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04: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 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04: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 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04: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 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=info msg="zeroconf server listening on port 42705"
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=debug msg="obtained new client token: AABNqL8xI26AOnvYhrkKAyFjYj1X+ATL3dq6H1tgOwBuhbwGQV6Xw2mULqu5TfYQKvv75EVdOkNy7ZYsC0pcy67D1NV7/AJ7y1kfgwQSJj9iL97YIO5XJeVglNpNUGhMpMgr6i4xWaG9oCi6cQxc0aAauZJSdi3k8xCGWlvjng8/ztiiu7NkpNf/82xHPnnJlr8955yBKqF/h76NILL3kZNBf/ZB2lB4B8IaKTRItkzsafW/il0lRbkO1A=="
Dec 06 12:04:21 volumio go-librespot[868]: time="2025-12-06T12:04:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:22 volumio go-librespot[868]: time="2025-12-06T12:04:22-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:22 volumio go-librespot[868]: time="2025-12-06T12:04:22-06:00" level=debug msg="completed challenge"
Dec 06 12:04:22 volumio go-librespot[868]: time="2025-12-06T12:04:22-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 06 12:04:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:22 volumio volumio[32717]: info: Connection to go-librespot Websocket closed
Dec 06 12:04:23 volumio volumio[32717]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 06 12:04:23 volumio volumio[32717]: 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 06 12:04:23 volumio volumio[32717]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:23 volumio volumio[32717]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:24 volumio volumio[32717]: info: Getting Spotify volume
Dec 06 12:04:24 volumio volumio[32717]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 12:04:24 volumio volumio[32717]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:24 volumio volumio[32717]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 06 12:04:24 volumio volumio[32717]: errno: -111,
Dec 06 12:04:24 volumio volumio[32717]: code: 'ECONNREFUSED',
Dec 06 12:04:24 volumio volumio[32717]: syscall: 'connect',
Dec 06 12:04:24 volumio volumio[32717]: address: '127.0.0.1',
Dec 06 12:04:24 volumio volumio[32717]: port: 9879,
Dec 06 12:04:24 volumio volumio[32717]: response: undefined
Dec 06 12:04:24 volumio volumio[32717]: }
Dec 06 12:04:24 volumio volumio[32717]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 12:04:25 volumio sudo[890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 12:03'
Dec 06 12:04:25 volumio sudo[890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:25 volumio sudo[890]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:25 volumio volumio-remote-updater[2353]: [2025-12-06 12:04:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Dec 06 12:04:25 volumio volumio-remote-updater[2353]: [2025-12-06 12:04:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Dec 06 12:04:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Dec 06 12:04:25 volumio systemd[1]: volumio.service: Consumed 46.370s CPU time.
Dec 06 12:04:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 12:04:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63.
Dec 06 12:04:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:25 volumio go-librespot[903]: go-librespot daemon starting...
Dec 06 12:04:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 12:04:25 volumio go-librespot[906]: time="2025-12-06T12:04:25-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:25 volumio go-librespot[906]: time="2025-12-06T12:04:25-06:00" level=debug msg="app state loaded"
Dec 06 12:04:25 volumio go-librespot[906]: time="2025-12-06T12:04:25-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:25 volumio go-librespot[906]: time="2025-12-06T12:04:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20958.
Dec 06 12:04:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 12:04:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Dec 06 12:04:25 volumio systemd[1]: volumio.service: Consumed 46.370s CPU time.
Dec 06 12:04:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 06 12:04:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-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 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-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 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-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 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-06:00" level=info msg="zeroconf server listening on port 32823"
Dec 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-06:00" level=debug msg="obtained new client token: AAB12tEPVxTUi+Jc6op3afSE9OPXD6bri5ZgGFiL24jlVZEtKm7dbk1jXRmU7nITxjPMps68Z8ZhGK2aIq526Po2x6gSuNTgbAThR4FPaANSMS3FCi1XMLLqaDIZUuzNmFYUusVXm6necZeLYJL75JtbQLmL50mBnFZ76VBwU6oaA+aRoun4MwRP2XFWsAquiDce7BXOHVtF08FWPRgQ09Mx5D4E/om2Y6nrZxHlhOL+EGX7n2PfQaw="
Dec 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-06:00" level=debug msg="completed challenge"
Dec 06 12:04:26 volumio go-librespot[906]: time="2025-12-06T12:04:26-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 06 12:04:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:27 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:27 volumio volumio[914]: info: ----- Volumio3 ----
Dec 06 12:04:27 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:27 volumio volumio[914]: info: ----- System startup ----
Dec 06 12:04:27 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:28 volumio volumio[914]: info: MYVOLUMIO Environment detected
Dec 06 12:04:28 volumio volumio[914]: info: Plugin folders cleanup
Dec 06 12:04:28 volumio volumio[914]: info: Scanning into folder /volumio/app/plugins/
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category audio_interface
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category miscellanea
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category music_service
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category plugins.json
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category system_controller
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category user_interface
Dec 06 12:04:28 volumio volumio[914]: info: Scanning into folder /data/plugins/
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category audio_interface
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category music_service
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category system_controller
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category system_hardware
Dec 06 12:04:28 volumio volumio[914]: info: Scanning category user_interface
Dec 06 12:04:28 volumio volumio[914]: info: Plugin folders cleanup completed
Dec 06 12:04:28 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:28 volumio volumio[914]: info: ----- Core plugins startup ----
Dec 06 12:04:28 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:28 volumio volumio[914]: info: Loading plugins from folder /volumio/app/plugins/
Dec 06 12:04:28 volumio volumio[914]: info: Adding plugin upnp to MyMusic Plugins
Dec 06 12:04:28 volumio volumio[914]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 06 12:04:28 volumio volumio[914]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 06 12:04:28 volumio volumio[914]: info: Loading plugins from folder /data/plugins/
Dec 06 12:04:28 volumio volumio[914]: info: Loading plugin "system"...
Dec 06 12:04:28 volumio volumio[914]: info: Loading plugin "appearance"...
Dec 06 12:04:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64.
Dec 06 12:04:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:29 volumio go-librespot[946]: go-librespot daemon starting...
Dec 06 12:04:29 volumio go-librespot[947]: time="2025-12-06T12:04:29-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:29 volumio go-librespot[947]: time="2025-12-06T12:04:29-06:00" level=debug msg="app state loaded"
Dec 06 12:04:29 volumio go-librespot[947]: time="2025-12-06T12:04:29-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:29 volumio go-librespot[947]: time="2025-12-06T12:04:29-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:29 volumio volumio[914]: info: Loading plugin "network"...
Dec 06 12:04:29 volumio volumio[914]: info: Refreshing Cached IP Addresses
Dec 06 12:04:30 volumio sudo[957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 12:04:30 volumio sudo[957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:30 volumio sudo[957]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:30 volumio sudo[959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "services"...
Dec 06 12:04:30 volumio sudo[959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "alsa_controller"...
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-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 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-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 06 12:04:30 volumio sudo[959]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-06:00" level=info msg="zeroconf server listening on port 36837"
Dec 06 12:04:30 volumio sudo[971]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 06 12:04:30 volumio sudo[971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:30 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "wizard"...
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "networkfs"...
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-06:00" level=debug msg="obtained new client token: AAAOim58Evo6uJ5Y8X90oN4k5BH9IDUbwWH05hNNTeVZiduDLJ7Z0Tt5/x7/ofxTJch4DjiGXedye3hhDE6gMgHW9kwyzfSMcr+qHztjgUmjup/xapQ3H8Ql6Ws6ncr5CiTBeloNeYcX6glPfLJoJQ1jSFJLkyDZRSKZ2CwbrAcxCxwazwdTLAMqHr6Ox6fZX+Fc8mTm+sQ5Pd5po+Rx87YODMr0sq+uY9LEysHGaZTa1t57hYf8RDE="
Dec 06 12:04:30 volumio volumio[914]: info: Starting Udev Watcher for removable devices
Dec 06 12:04:30 volumio volumio[914]: info: Ignoring mount for partition: boot
Dec 06 12:04:30 volumio volumio[914]: info: Ignoring mount for partition: volumio
Dec 06 12:04:30 volumio volumio[914]: info: Ignoring mount for partition: volumio_data
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:30 volumio volumio[914]: info: Mounting Device Wikipedia
Dec 06 12:04:30 volumio sudo[999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Dec 06 12:04:30 volumio sudo[999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-06:00" level=debug msg="completed challenge"
Dec 06 12:04:30 volumio sudo[999]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:30 volumio volumio[914]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Dec 06 12:04:30 volumio volumio[914]: dmesg(1) may have more information after failed mount system call.
Dec 06 12:04:30 volumio volumio[914]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Dec 06 12:04:30 volumio volumio[914]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Dec 06 12:04:30 volumio volumio[914]: dmesg(1) may have more information after failed mount system call.
Dec 06 12:04:30 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "volumio_command_line_client"...
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "upnp"...
Dec 06 12:04:30 volumio volumio[914]: info: [1765044270313] Starting Upmpd Daemon
Dec 06 12:04:30 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "my_music"...
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "mpd"...
Dec 06 12:04:30 volumio go-librespot[947]: time="2025-12-06T12:04:30-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 06 12:04:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:30 volumio sudo[971]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:30 volumio volumio[914]: info: Loading plugin "upnp_browser"...
Dec 06 12:04:30 volumio volumio-remote-updater[2353]: [2025-12-06 12:04:30] [connect] Successful connection
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "alarm-clock"...
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "airplay_emulation"...
Dec 06 12:04:32 volumio volumio[914]: info: Starting Shairport Sync
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "last_100"...
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "webradio"...
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "i2s_dacs"...
Dec 06 12:04:32 volumio volumio[914]: info: I2S DAC not set, start Auto-detection
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "volumiodiscovery"...
Dec 06 12:04:32 volumio volumio[914]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:04:32 volumio volumio[914]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:04:32 volumio volumio[914]: *** WARNING *** For more information see
Dec 06 12:04:32 volumio volumio[914]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:04:32 volumio volumio[914]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:04:32 volumio volumio[914]: *** WARNING *** For more information see
Dec 06 12:04:32 volumio node[914]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:04:32 volumio node[914]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:04:32 volumio node[914]: *** WARNING *** For more information see
Dec 06 12:04:32 volumio node[914]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:04:32 volumio node[914]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:04:32 volumio node[914]: *** WARNING *** For more information see
Dec 06 12:04:32 volumio volumio[914]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 06 12:04:32 volumio volumio[914]: info: Discovery: Started advertising with name: Volumio
Dec 06 12:04:32 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 12:04:32 volumio volumio[914]: info: Loading plugin "bandcamp"...
Dec 06 12:04:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65.
Dec 06 12:04:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:33 volumio go-librespot[1010]: go-librespot daemon starting...
Dec 06 12:04:33 volumio go-librespot[1011]: time="2025-12-06T12:04:33-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:33 volumio go-librespot[1011]: time="2025-12-06T12:04:33-06:00" level=debug msg="app state loaded"
Dec 06 12:04:33 volumio go-librespot[1011]: time="2025-12-06T12:04:33-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:33 volumio go-librespot[1011]: time="2025-12-06T12:04:33-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:33 volumio volumio[914]: info: Plugin calmradio is not enabled
Dec 06 12:04:33 volumio volumio[914]: info: Loading plugin "soundcloud"...
Dec 06 12:04:34 volumio volumio[914]: info: Loading plugin "spop"...
Dec 06 12:04:35 volumio volumio[914]: info: Loading plugin "squeezelite_mc"...
Dec 06 12:04:35 volumio volumio[914]: info: Loading plugin "youtube2"...
Dec 06 12:04:36 volumio volumio[914]: info: Loading plugin "ytcr"...
Dec 06 12:04:37 volumio volumio[914]: info: Loading plugin "ytmusic"...
Dec 06 12:04:38 volumio volumio[914]: info: Plugin now_playing is not enabled
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "outputs"...
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "albumart"...
Dec 06 12:04:38 volumio volumio[914]: info: Plugin example_plugin is not enabled
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "inputs"...
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "updater_comm"...
Dec 06 12:04:38 volumio volumio[914]: info: Plugin mpdemulation is not enabled
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "rest_api"...
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "websocket"...
Dec 06 12:04:38 volumio volumio[914]: info: Starting Socket.io Server version 1.7.4
Dec 06 12:04:38 volumio volumio[914]: info: Plugin fusiondsp is not enabled
Dec 06 12:04:38 volumio volumio[914]: info: Plugin mpdoutput is not enabled
Dec 06 12:04:38 volumio volumio[914]: info: Plugin RoonBridge is not enabled
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "podcast"...
Dec 06 12:04:38 volumio volumio[914]: info: ControllerPodcast::constructor
Dec 06 12:04:38 volumio volumio[914]: info: Loading plugin "volusonic"...
Dec 06 12:04:38 volumio volumio[1017]: Forking 3 albumart workers
Dec 06 12:04:40 volumio volumio[1028]: Starting albumart workers
Dec 06 12:04:40 volumio volumio[914]: info: Applying required configuration parameters for plugin volusonic
Dec 06 12:04:40 volumio volumio[914]: info: Loading plugin "backup_restore"...
Dec 06 12:04:40 volumio volumio[1029]: Starting albumart workers
Dec 06 12:04:40 volumio volumio[1027]: Starting albumart workers
Dec 06 12:04:40 volumio volumio[914]: info: Applying required configuration parameters for plugin backup_restore
Dec 06 12:04:40 volumio volumio[914]: info: Plugin rpi_eeprom_config is not enabled
Dec 06 12:04:40 volumio volumio[914]: info: Plugin rpi_eeprom_updater is not enabled
Dec 06 12:04:40 volumio volumio[914]: info: Loading plugin "scheduledrestart"...
Dec 06 12:04:40 volumio go-librespot[1011]: time="2025-12-06T12:04:40-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 06 12:04:40 volumio go-librespot[1011]: time="2025-12-06T12:04:40-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 06 12:04:40 volumio go-librespot[1011]: time="2025-12-06T12:04:40-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 06 12:04:40 volumio go-librespot[1011]: time="2025-12-06T12:04:40-06:00" level=info msg="zeroconf server listening on port 33389"
Dec 06 12:04:41 volumio go-librespot[1011]: time="2025-12-06T12:04:41-06:00" level=debug msg="obtained new client token: AADBC90IJC8CeB9Y/ZQhwtr4Wrcexcmsw+BktWHSZ/rI0t/Q84kZOyqwKbuVDNvjV3Ok4k5nXXXLnNJdx3HiE6Ksnkr+NabdXIK4dP7smEHV0dQlFLjSu3rtSqSe2G8lz7sF96XKcLVPYPOFP4ndbLdg2dBh4bJ00VVimxAunUKtdJ+s/SAL/6Anulj0pax+ZDuXtaS9Xt99DCxaBQZHM+jJFBjoINTBJXPkfUM98HzjAcVPhU486LM="
Dec 06 12:04:41 volumio volumio[914]: info: Applying required configuration parameters for plugin scheduledrestart
Dec 06 12:04:41 volumio volumio[914]: info: Plugin Bluetoothremote is not enabled
Dec 06 12:04:41 volumio volumio[914]: info: Plugin music_services_shield is not enabled
Dec 06 12:04:41 volumio volumio[914]: info: Loading plugin "Systeminfo"...
Dec 06 12:04:41 volumio go-librespot[1011]: time="2025-12-06T12:04:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:41 volumio volumio[914]: info: Plugin peppymeterbasic is not enabled
Dec 06 12:04:41 volumio volumio[914]: info: Loading plugin "peppyspectrum"...
Dec 06 12:04:41 volumio go-librespot[1011]: time="2025-12-06T12:04:41-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:41 volumio go-librespot[1011]: time="2025-12-06T12:04:41-06:00" level=debug msg="completed challenge"
Dec 06 12:04:41 volumio go-librespot[1011]: time="2025-12-06T12:04:41-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 06 12:04:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:41 volumio volumio[914]: info: Loading i18n strings for locale en
Dec 06 12:04:41 volumio volumio[914]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Dec 06 12:04:41 volumio volumio[914]: Updating browse sources language
Dec 06 12:04:41 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::initPlayerControls
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: Express server listening on port 3000
Dec 06 12:04:42 volumio volumio[914]: [Metrics] WebUI: 14s 620.16ms
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::resetVolumioState
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::getcurrentVolume
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:42 volumio sudo[1108]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 12:04:42 volumio sudo[1108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio sudo[1108]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:42 volumio sudo[1110]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 12:04:42 volumio sudo[1110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio sudo[1110]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:42 volumio volumio[914]: info: Volumio Network Manager: Network status updated: 1
Dec 06 12:04:42 volumio volumio[914]: info: VolumeController:: Volume=86 Mute =false
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::pushState
Dec 06 12:04:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioPushState
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock
Dec 06 12:04:42 volumio volumio[914]: info: CorePlayQueue::getTrackBlock
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 12:04:42 volumio volumio[914]: info: Reloading queue from file
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::setRepeat null single undefined
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::pushState
Dec 06 12:04:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioPushState
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::setRandom null
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::pushState
Dec 06 12:04:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioPushState
Dec 06 12:04:42 volumio volumio[914]: info: Setting Device type: Raspberry PI
Dec 06 12:04:42 volumio volumio[914]: info: VolumeController:: Volume=86 Mute =false
Dec 06 12:04:42 volumio volumio[914]: info: CoreStateMachine::pushState
Dec 06 12:04:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioPushState
Dec 06 12:04:42 volumio sudo[1122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 06 12:04:42 volumio sudo[1122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio volumio[914]: info: Completed loading Core Plugins
Dec 06 12:04:42 volumio volumio[914]: info: Preparing to generate the ALSA configuration file
Dec 06 12:04:42 volumio sudo[1122]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:42 volumio volumio[914]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Dec 06 12:04:42 volumio volumio[914]: info: Discovery: Found device Volumio
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:42 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:42 volumio volumio[914]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Dec 06 12:04:42 volumio volumio[914]: info: Reading ALSA contributions from plugins.
Dec 06 12:04:42 volumio volumio[914]: info: Upmpdcli Daemon Started
Dec 06 12:04:42 volumio volumio[914]: info: Asound.conf file unchanged, so no further update is needed
Dec 06 12:04:42 volumio volumio[914]: info: Output device has changed, restarting MPD
Dec 06 12:04:42 volumio volumio[914]: info: Output device has changed, restarting Shairport Sync
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:42 volumio sudo[1126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 12:04:42 volumio sudo[1126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio sudo[1128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 12:04:42 volumio sudo[1128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio sudo[1126]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:42 volumio volumio[914]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:04:42 volumio volumio[914]: info: ___________ START PLUGINS ___________
Dec 06 12:04:42 volumio volumio[914]: info: ControllerMpd::onStart: Initializing MPD
Dec 06 12:04:42 volumio volumio[914]: info: Creating MPD Configuration file
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:42 volumio volumio[914]: info: [1765044282592] CoreMusicLibrary::Adding element Media Servers
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 12:04:42 volumio sudo[1136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 12:04:42 volumio sudo[1136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio sudo[1136]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:42 volumio sudo[1138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 12:04:42 volumio sudo[1138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:42 volumio volumio[914]: info: [1765044282703] CoreMusicLibrary::Adding element Last_100
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:42 volumio systemd[1]: mpd.service: Deactivated successfully.
Dec 06 12:04:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 12:04:42 volumio systemd[1]: mpd.service: Consumed 4.532s CPU time.
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:42 volumio systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 12:04:42 volumio volumio[914]: info: [1765044282708] CoreMusicLibrary::Adding element Webradio
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 12:04:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:04:42 volumio volumio[914]: info: Initializing BBC Radios
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:42 volumio volumio[914]: info: [1765044282779] CoreMusicLibrary::Adding element Bandcamp Discover
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:42 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:42 volumio volumio[914]: info: [1765044282790] CoreMusicLibrary::Adding element SoundCloud
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:42 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:42 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 12:04:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 12:04:42 volumio volumio[914]: info: Creating Spotify config file
Dec 06 12:04:42 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio sudo[1164]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 12:04:43 volumio sudo[1164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 12:04:43 volumio sudo[1164]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:43 volumio volumio[914]: info: [squeezelite_mc] Starting proxy server...
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:43 volumio volumio[914]: info: [1765044283161] CoreMusicLibrary::Adding element YouTube2
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:43 volumio volumio[914]: info: [1765044283181] CoreMusicLibrary::Adding element YouTube Music
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube Music
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:43 volumio volumio[914]: info: [1765044283193] CoreMusicLibrary::Adding element Podcast
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube Music
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Podcast
Dec 06 12:04:43 volumio volumio[914]: info: Loading i18n strings for locale en
Dec 06 12:04:43 volumio volumio[914]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Dec 06 12:04:43 volumio volumio[914]: Updating browse sources language
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube Music
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Podcast
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube Music
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Podcast
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:43 volumio volumio[914]: info: [1765044283241] CoreMusicLibrary::Adding element Volusonic
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source YouTube Music
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Podcast
Dec 06 12:04:43 volumio volumio[914]: Cannot find translation for source Volusonic
Dec 06 12:04:43 volumio volumio[914]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Dec 06 12:04:43 volumio volumio-remote-updater[2353]: [2025-12-06 12:04:43] [connect] Successful connection
Dec 06 12:04:43 volumio volumio[914]: info: Volumio Calling Home
Dec 06 12:04:43 volumio volumio[914]: info: [squeezelite_mc] Proxy server started on port 46049
Dec 06 12:04:43 volumio volumio[914]: info: Preparing to generate the ALSA configuration file
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 12:04:43 volumio volumio[914]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954
Dec 06 12:04:43 volumio volumio[914]: info: Discovery: Found device Volumio
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:43 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:43 volumio volumio[914]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Dec 06 12:04:43 volumio volumio[914]: info: Reading ALSA contributions from plugins.
Dec 06 12:04:43 volumio volumio[914]: info: MPD Permissions set
Dec 06 12:04:43 volumio volumio[914]: info: MPD Permissions set
Dec 06 12:04:43 volumio volumio-remote-updater[2353]: [2025-12-06 12:04:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765044283 101
Dec 06 12:04:43 volumio volumio[914]: 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 06 12:04:43 volumio volumio[914]: info: Spotify config file written
Dec 06 12:04:43 volumio sudo[1178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 06 12:04:43 volumio sudo[1178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:43 volumio volumio[914]: 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 06 12:04:43 volumio volumio[914]: info: VolumeController:: Volume=86 Mute =false
Dec 06 12:04:43 volumio volumio[914]: info: CoreStateMachine::pushState
Dec 06 12:04:43 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::volumioPushState
Dec 06 12:04:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:43 volumio go-librespot[1180]: go-librespot daemon starting...
Dec 06 12:04:43 volumio sudo[1178]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:43 volumio volumio[914]: info: [squeezelite_mc] Server discovery started
Dec 06 12:04:43 volumio volumio[914]: info: [squeezelite_mc] Player finder started
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true
Dec 06 12:04:43 volumio go-librespot[1181]: time="2025-12-06T12:04:43-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:43 volumio go-librespot[1181]: time="2025-12-06T12:04:43-06:00" level=debug msg="app state loaded"
Dec 06 12:04:43 volumio go-librespot[1181]: time="2025-12-06T12:04:43-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:43 volumio go-librespot[1181]: time="2025-12-06T12:04:43-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:43 volumio volumio[914]: info: No need to fix Spotify hosts
Dec 06 12:04:43 volumio volumio[914]: 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 06 12:04:44 volumio volumio[914]: info: Volumio called home
Dec 06 12:04:44 volumio volumio[914]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 06 12:04:44 volumio volumio[914]: SPOTIFY: BQDBKHAHsCfgtBLkLQyoFAQ7LypdBeuYb8Xn0e3lE3plNexm8CF6q5-s48SVcNS7fI3DFRui1kU-B3Dy4GAcUVG9wQHWBmom2GSeLdcDsWv1Rp_Zd_WU25MkpWhrGe37RyaUhjDGaeyRQQAqY37XW1yE7FprHbynQ-LT7QjhSbvJCdadxFYs13q_qv1D7JcX8uW6ijsCEWV7GIio65LMpCnBtK66Pg0GyOI4Hx8
Dec 06 12:04:44 volumio volumio[914]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 06 12:04:44 volumio volumio[914]: info: New Spotify access token = BQDBKHAHsCfgtBLkLQyoFAQ7LypdBeuYb8Xn0e3lE3plNexm8CF6q5-s48SVcNS7fI3DFRui1kU-B3Dy4GAcUVG9wQHWBmom2GSeLdcDsWv1Rp_Zd_WU25MkpWhrGe37RyaUhjDGaeyRQQAqY37XW1yE7FprHbynQ-LT7QjhSbvJCdadxFYs13q_qv1D7JcX8uW6ijsCEWV7GIio65LMpCnBtK66Pg0GyOI4Hx8
Dec 06 12:04:44 volumio volumio[914]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-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 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-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 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-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 06 12:04:44 volumio volumio[914]: 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 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-06:00" level=info msg="zeroconf server listening on port 39945"
Dec 06 12:04:44 volumio volumio[914]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Dec 06 12:04:44 volumio volumio[914]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Dec 06 12:04:44 volumio volumio[914]: 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 06 12:04:44 volumio volumio[914]: info: Starting Shairport Sync
Dec 06 12:04:44 volumio volumio[914]: info: Starting Shairport Sync
Dec 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-06:00" level=debug msg="obtained new client token: AABlXpQ6sxcmp3ph5D9TKfaB6nEqghNl1Ui1lgM18dIOZ1CVJTD5xvlXyiprKY4JZi4W6k5K6xUfEjKiNXiXFEyvkndksFV7xpe56wLIcR1PO+ryfthnHqRDNJb1OzSS89bo6zHY/Bxrd+7BmVE+IFQDshbCw+WCUEV+48NdIFiX72mkQpHwn8+LDy7thfUnKg4Ic3l36FPqu/72PlSyhZihC6O6PvRNZz+vhnm9n9U2IIKuPvAM5NM="
Dec 06 12:04:44 volumio volumio[914]: info: Starting Shairport Sync
Dec 06 12:04:44 volumio sudo[1206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:04:44 volumio sudo[1206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio sudo[1209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:04:44 volumio sudo[1209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:44 volumio sudo[1211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:04:44 volumio sudo[1211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio sudo[1203]: 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 06 12:04:44 volumio sudo[1203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-06:00" level=debug msg="completed challenge"
Dec 06 12:04:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 12:04:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 12:04:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:04:44 volumio systemd[1]: shairport-sync.service: Consumed 2.035s CPU time.
Dec 06 12:04:44 volumio sudo[1203]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio go-librespot[1181]: time="2025-12-06T12:04:44-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 06 12:04:44 volumio volumio[914]: info: Asound.conf file unchanged, so no further update is needed
Dec 06 12:04:44 volumio volumio[914]: info: Output device has changed, restarting MPD
Dec 06 12:04:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:04:44 volumio sudo[1209]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:44 volumio sudo[1211]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio volumio[914]: info: Output device has changed, restarting Shairport Sync
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:44 volumio sudo[1206]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio sudo[1219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 12:04:44 volumio sudo[1219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio sudo[1221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 12:04:44 volumio sudo[1221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio sudo[1219]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio volumio[914]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:04:44 volumio systemd[1]: mpd.service: Deactivated successfully.
Dec 06 12:04:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 12:04:44 volumio systemd[1]: mpd.service: Consumed 1.569s CPU time.
Dec 06 12:04:44 volumio systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 12:04:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 12:04:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 12:04:44 volumio volumio[914]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Dec 06 12:04:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 12:04:44 volumio sudo[1248]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Dec 06 12:04:44 volumio sudo[1248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 12:04:44 volumio sudo[1248]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio volumio[914]: info: MPD Permissions set
Dec 06 12:04:44 volumio volumio[914]: info: Shairport-Sync Started
Dec 06 12:04:44 volumio volumio[914]: Error adding Membership: Error: addMembership EINVAL
Dec 06 12:04:44 volumio volumio[914]: info: Shairport-Sync Started
Dec 06 12:04:44 volumio volumio[914]: info: Shairport-Sync Started
Dec 06 12:04:44 volumio volumio[914]: 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 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:44 volumio volumio[914]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:44 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:44 volumio sudo[1250]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 12:04:44 volumio sudo[1250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 12:04:44 volumio sudo[1250]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio sudo[1254]: 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 06 12:04:44 volumio sudo[1254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:44 volumio sudo[1254]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:44 volumio volumio[914]: info: Starting Shairport Sync
Dec 06 12:04:44 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Dec 06 12:04:45 volumio sudo[1264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:04:45 volumio sudo[1264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:45 volumio volumio[914]: 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 06 12:04:45 volumio volumio[914]: info: Spotify Successfully logged in
Dec 06 12:04:45 volumio volumio[914]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:04:45 volumio sudo[1267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Dec 06 12:04:45 volumio sudo[1267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:45 volumio volumio[914]: info: [1765044285057] CoreMusicLibrary::Adding element Spotify
Dec 06 12:04:45 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source Bandcamp Discover
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source SoundCloud
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source YouTube2
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source YouTube Music
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source Podcast
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source Volusonic
Dec 06 12:04:45 volumio volumio[914]: Cannot find translation for source Spotify
Dec 06 12:04:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 12:04:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 12:04:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:04:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:04:45 volumio sudo[1264]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:45 volumio volumio[914]: info: Shairport-Sync Started
Dec 06 12:04:45 volumio systemd[1]: Reloading.
Dec 06 12:04:45 volumio volumio[914]: info: [squeezelite_mc] Notification listener started
Dec 06 12:04:45 volumio volumio[914]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180)
Dec 06 12:04:45 volumio volumio[914]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"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"}},{"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"}}]
Dec 06 12:04:45 volumio volumio[914]: 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 06 12:04:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:04:46 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:04:47 volumio volumio[914]: info: go-librespot daemon successfully initialized
Dec 06 12:04:47 volumio volumio[914]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:47 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:47 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 06 12:04:47 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 06 12:04:47 volumio sudo[1267]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:47 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:47 volumio sudo[1302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:47 volumio sudo[1302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66.
Dec 06 12:04:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:47 volumio go-librespot[1304]: go-librespot daemon starting...
Dec 06 12:04:47 volumio sudo[1302]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:47 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-06:00" level=debug msg="app state loaded"
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:47 volumio sudo[1312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Dec 06 12:04:47 volumio sudo[1312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:47 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Dec 06 12:04:47 volumio volumio[914]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect'
Dec 06 12:04:47 volumio volumio[914]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:47 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04: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-gew4.spotify.com:80]"
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-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 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-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 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-06:00" level=info msg="zeroconf server listening on port 46363"
Dec 06 12:04:47 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Dec 06 12:04:47 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Dec 06 12:04:47 volumio go-librespot[1305]: time="2025-12-06T12:04:47-06:00" level=debug msg="obtained new client token: AAAtDiyqOyZYnVtqyStF6Sk2HNniKanBX+jMyrv/bpNyAPu/moMmy9HRoLzDeVGRRxgJ2wD5FsvH9lPW5rrq8AYhMWcGvdOARsApBE9G5k1fUke7s0swc9p77uLH53mu0StIWd+2NDez0qldokPcZzc0jrlOMmvp01m08SGf/pUrKfM+vkNENlWlI0/23G/XEtcgfsDoEX94lCYBUxtLjO3nOWyMIeTUgAqx3sfRbGH46eZ5J38yunzEhg=="
Dec 06 12:04:47 volumio sudo[1312]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio go-librespot[1305]: time="2025-12-06T12:04:48-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 06 12:04:48 volumio go-librespot[1305]: time="2025-12-06T12:04:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Dec 06 12:04:48 volumio go-librespot[1305]: time="2025-12-06T12:04:48-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:48 volumio go-librespot[1305]: time="2025-12-06T12:04:48-06:00" level=debug msg="completed challenge"
Dec 06 12:04:48 volumio go-librespot[1305]: time="2025-12-06T12:04:48-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 06 12:04:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:48 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:48 volumio sudo[1316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:48 volumio sudo[1316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:48 volumio sudo[1316]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio volumio[914]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Dec 06 12:04:48 volumio sudo[1320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Dec 06 12:04:48 volumio sudo[1320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:48 volumio sudo[1320]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Dec 06 12:04:48 volumio mpd[1261]: 2025-12-06T12:04:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 12:04:48 volumio sudo[1323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Dec 06 12:04:48 volumio sudo[1323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:48 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Dec 06 12:04:48 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Dec 06 12:04:48 volumio sudo[1323]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 12:04:48 volumio sudo[1128]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio sudo[1221]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio sudo[1138]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:48 volumio volumio[914]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect'
Dec 06 12:04:48 volumio volumio[914]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180)
Dec 06 12:04:49 volumio volumio[914]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 12:04:49 volumio volumio[914]: assert.ok(self.idling)
Dec 06 12:04:49 volumio volumio[914]: error: The expression evaluated to a falsy value:
Dec 06 12:04:49 volumio volumio[914]: assert.ok(self.idling)
Dec 06 12:04:49 volumio volumio[914]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 12:04:49 volumio volumio[914]: assert.ok(self.idling)
Dec 06 12:04:49 volumio volumio[914]: error: The expression evaluated to a falsy value:
Dec 06 12:04:49 volumio volumio[914]: assert.ok(self.idling)
Dec 06 12:04:49 volumio volumio[914]: error: updateQueue error: null
Dec 06 12:04:49 volumio volumio[914]: info: MPD running with PID1261
Dec 06 12:04:49 volumio volumio[914]: ,establishing connection
Dec 06 12:04:49 volumio volumio[914]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"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"}},{"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"}}]
Dec 06 12:04:49 volumio volumio[914]: 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 06 12:04:49 volumio volumio[914]: error: updateQueue error: null
Dec 06 12:04:49 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:49 volumio sudo[1334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:49 volumio sudo[1334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:49 volumio sudo[1334]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:49 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:49 volumio sudo[1337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:49 volumio sudo[1337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:49 volumio sudo[1337]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:50 volumio volumio[914]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:50 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:50 volumio volumio[914]: info: CoreCommandRouter::volumioGetState
Dec 06 12:04:50 volumio volumio[914]: info: CorePlayQueue::getTrack 0
Dec 06 12:04:50 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:50 volumio sudo[1354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:50 volumio sudo[1354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:50 volumio sudo[1354]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:51 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:51 volumio sudo[1357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:51 volumio sudo[1357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:51 volumio sudo[1357]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67.
Dec 06 12:04:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:51 volumio go-librespot[1359]: go-librespot daemon starting...
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=debug msg="app state loaded"
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:51 volumio volumio[914]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:04:51 volumio sudo[1368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:04:51 volumio sudo[1368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-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 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-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 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-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 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=info msg="zeroconf server listening on port 44165"
Dec 06 12:04:51 volumio sudo[1368]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:51 volumio volumio[914]: info: Completed starting Core Plugins
Dec 06 12:04:51 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:51 volumio volumio[914]: info: ----- MyVolumio plugins startup ----
Dec 06 12:04:51 volumio volumio[914]: info: -------------------------------------------
Dec 06 12:04:51 volumio volumio[914]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=debug msg="obtained new client token: AADhv+x5VwpziNJvwXiYZq9snvb+5/0Kq2uHu/CC0P9VmHtKqSC+eRw5i2Qkz6IDAPc34AKEy1y9fp5Qg0WqSCPzgfPDR7Fy4+qyfdRvlYf9MRDn0/udxk6VG+RO/CfuI/K2oqFUKYhQMX9fY+sSpVpo/3WrAniDVbU0IeUzKrz7x/lvmB9WR8YnyGEfCBeKHn0hYpaQVwuquNBOFu7jFW3gCi1gSEpI0FrRcRITFkymQ7BOnoziGc1Xmg=="
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:51 volumio sudo[1371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 12:04:51 volumio sudo[1371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-06:00" level=debug msg="completed challenge"
Dec 06 12:04:51 volumio sudo[1373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 12:04:51 volumio sudo[1373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:51 volumio sudo[1376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 12:04:51 volumio sudo[1376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:04:51 volumio go-librespot[1360]: time="2025-12-06T12:04:51-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 06 12:04:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:52 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 12:04:52 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 12:04:52 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 12:04:52 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 12:04:52 volumio sudo[1373]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:52 volumio sudo[1371]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:52 volumio mpd_monitor.sh[1379]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 12:04:52 volumio sudo[1376]: pam_unix(sudo:session): session closed for user root
Dec 06 12:04:52 volumio volumio[914]: info: Successfully started MPD Monitor
Dec 06 12:04:52 volumio volumio[914]: info: Successfully started MPD Monitor
Dec 06 12:04:52 volumio volumio[914]: info: Successfully started MPD Monitor
Dec 06 12:04:53 volumio volumio[914]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:53 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68.
Dec 06 12:04:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:55 volumio go-librespot[1383]: go-librespot daemon starting...
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=debug msg="app state loaded"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-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 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-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 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=info msg="zeroconf server listening on port 33571"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=debug msg="obtained new client token: AAAKYjIaIC/V6vNxyGUYcjCsU/eHfPtB4YjRtj/3uYRhc2asyFy1yfNUf/Ci+ByUejKwLLt+i5oicWRhy6K8OtJjYMEsd5PRL7aPXSWV2kW7sKX6E9MsghST48wB712NqtF9k6p5oV7pJ8ww6t26vFkCLtvUTD+kgGkoXyECp44Xdu7HJT67yzy7+969B0sjTs4btckmETLMKIB3K754JDSLqw3sVR29Oyas7NZ9SmKf0j9K4t54/YoAfw=="
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04:55-06:00" level=debug msg="completed challenge"
Dec 06 12:04:55 volumio go-librespot[1384]: time="2025-12-06T12:04: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 06 12:04:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:56 volumio volumio[914]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:56 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:04:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69.
Dec 06 12:04:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:04:58 volumio go-librespot[1392]: go-librespot daemon starting...
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=debug msg="app state loaded"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=debug msg="stored credentials not found"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-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 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-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 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=info msg="zeroconf server listening on port 34277"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=debug msg="obtained new client token: AABf0qkhUmW8i1IlMgOgqm4vVYkzxyJaugv2A54Fnu2TsBD3MIobyuPc6DFdBUrAjpIoKXRkErl7QQO+BIAL/fy1iT7XTOvZpiBOKdfZ+4sn3KEYwIC0sl7iy8SQrxRn5zEjviMEpbNgqnvF7z08VFmG8tO4yfLd9JvIWwIRyfn59Dh9KJvADJLcrU8eRuNAaJYq5w8bU5UWFnVWsNIVj7gZDM1iYFH+1JiLcJfOIB4kpzAyooy+fYBhIg=="
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=debug msg="completed keyexchange"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-06:00" level=debug msg="completed challenge"
Dec 06 12:04:59 volumio go-librespot[1393]: time="2025-12-06T12:04:59-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 06 12:04:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:04:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:04:59 volumio volumio[914]: info: Initializing connection to go-librespot Websocket
Dec 06 12:04:59 volumio volumio[914]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin multiroom to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 06 12:05:00 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 06 12:05:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:00 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:00 volumio volumio[914]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 06 12:05:01 volumio volumio[914]: info: MyVolumio login type: Token
Dec 06 12:05:01 volumio volumio[914]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 06 12:05:01 volumio volumio[914]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 06 12:05:01 volumio volumio[914]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 06 12:05:01 volumio volumio[914]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 06 12:05:01 volumio volumio[914]: info: Streaming services startup
Dec 06 12:05:01 volumio volumio[914]: info: Starting Streaming Daemon
Dec 06 12:05:01 volumio sudo[1416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 12:05:01 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:01 volumio volumio[914]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 06 12:05:01 volumio sudo[1416]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:01 volumio volumio[914]: error: Cannot start Volumio Streaming Daemon
Dec 06 12:05:01 volumio volumio[914]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 12:05:01 volumio volumio[914]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 12:05:02 volumio volumio[914]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 06 12:05:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70.
Dec 06 12:05:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:02 volumio go-librespot[1424]: go-librespot daemon starting...
Dec 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-06:00" level=debug msg="app state loaded"
Dec 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:02 volumio volumio[914]: info: Initializing connection to go-librespot Websocket
Dec 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-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 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-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 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-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 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-06:00" level=debug msg="new websocket client"
Dec 06 12:05:02 volumio volumio[914]: info: Connection to go-librespot Websocket established
Dec 06 12:05:02 volumio volumio[914]: info: MyVolumio token set successfully
Dec 06 12:05:02 volumio volumio[914]: info: MYVOLUMIO: Adding device
Dec 06 12:05:02 volumio volumio[914]: info: MYVOLUMIO: Evaluating Server
Dec 06 12:05:02 volumio go-librespot[1425]: time="2025-12-06T12:05:02-06:00" level=info msg="zeroconf server listening on port 44243"
Dec 06 12:05:03 volumio go-librespot[1425]: time="2025-12-06T12:05:03-06:00" level=debug msg="obtained new client token: AAB+9M98Vea3/sT1FpP1v+oRbWAVOEL3g4IK/P5AaEngF9oiQFtNJSgZwMJRT1l+88VSXOAqT8IXlpov3g/ZZWq5XUh0QjNFLnewcP0zLrUWGTvmwefq4/xWEF5oFB6yQDn7IruxyO/DjdHWgj/F0yBp66w+cbhhbvAMTuTSb5QTwWxOSM+ikmRtKoPwXowFCLIjLu4dsV9pL5cwwwUYpoWQmyinlx2Gdqj0XWQEO/EZr4pAYKVBSXI="
Dec 06 12:05:03 volumio go-librespot[1425]: time="2025-12-06T12:05:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:03 volumio go-librespot[1425]: time="2025-12-06T12:05:03-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:03 volumio go-librespot[1425]: time="2025-12-06T12:05:03-06:00" level=debug msg="completed challenge"
Dec 06 12:05:03 volumio volumio[914]: info: MyVolumio status changed
Dec 06 12:05:03 volumio volumio[914]: info: Streaming services startup
Dec 06 12:05:03 volumio volumio[914]: info: Starting Streaming Daemon
Dec 06 12:05:03 volumio go-librespot[1425]: time="2025-12-06T12:05:03-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 06 12:05:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:03 volumio volumio[914]: info: Removing browser output: myVolumio user plan is not superstar
Dec 06 12:05:03 volumio volumio[914]: info: Removing audio output:
Dec 06 12:05:03 volumio volumio[914]: info: Stoppping Tunnel 1
Dec 06 12:05:03 volumio sudo[1451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 12:05:03 volumio sudo[1451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:03 volumio sudo[1453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Dec 06 12:05:03 volumio sudo[1453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:03 volumio volumio[914]: info: Connection to go-librespot Websocket closed
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio sudo[1451]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:03 volumio volumio[914]: error: Cannot start Volumio Streaming Daemon
Dec 06 12:05:03 volumio volumio[914]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 12:05:03 volumio volumio[914]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 06 12:05:03 volumio sudo[1453]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:03 volumio volumio[914]: info: Remote SSH Stopped
Dec 06 12:05:03 volumio volumio[914]: info: Setting Geolocation for MyVolumio to us4
Dec 06 12:05:03 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:03 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:03 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:03 volumio volumio[914]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Dec 06 12:05:04 volumio volumio[914]: info: Updating MyVolumio device info
Dec 06 12:05:04 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:04 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:04 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:04 volumio volumio[914]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Dec 06 12:05:06 volumio volumio[914]: info: Getting Spotify volume
Dec 06 12:05:06 volumio volumio[914]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 12:05:06 volumio volumio[914]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:05:06 volumio volumio[914]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 06 12:05:06 volumio volumio[914]: errno: -111,
Dec 06 12:05:06 volumio volumio[914]: code: 'ECONNREFUSED',
Dec 06 12:05:06 volumio volumio[914]: syscall: 'connect',
Dec 06 12:05:06 volumio volumio[914]: address: '127.0.0.1',
Dec 06 12:05:06 volumio volumio[914]: port: 9879,
Dec 06 12:05:06 volumio volumio[914]: response: undefined
Dec 06 12:05:06 volumio volumio[914]: }
Dec 06 12:05:06 volumio volumio[914]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 12:05:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71.
Dec 06 12:05:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:06 volumio go-librespot[1469]: go-librespot daemon starting...
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=debug msg="app state loaded"
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-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 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-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 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-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 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=info msg="zeroconf server listening on port 38315"
Dec 06 12:05:06 volumio sudo[1485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 12:04'
Dec 06 12:05:06 volumio sudo[1485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=debug msg="obtained new client token: AAA1Kk5MUtd6OW9MNXHtA9se7E+lI8nuZ4q69wl/bUnrg9Qwf85pd8AXCEW7scRiTYnNZID2jXBLAlA4LUISWPYFBT7uyCv6uzURLw43aF55mPSZfjsmDacsnqr6njyn1rOjnoiQztsl0ErhBoK98JP2E3y8j5o48znjcI5dJwH5RjcaDWPvMNmUjhI7SCju8pKGE32p6uScouqoK2RWY1VhQd9UW9VabqkVpol4PyVfjdCvXFrC3J7n1g=="
Dec 06 12:05:06 volumio go-librespot[1471]: time="2025-12-06T12:05:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:07 volumio sudo[1485]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:07 volumio go-librespot[1471]: time="2025-12-06T12:05:07-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:07 volumio go-librespot[1471]: time="2025-12-06T12:05:07-06:00" level=debug msg="completed challenge"
Dec 06 12:05:07 volumio go-librespot[1471]: time="2025-12-06T12:05:07-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 06 12:05:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:07 volumio volumio-remote-updater[2353]: [2025-12-06 12:05:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Dec 06 12:05:07 volumio volumio-remote-updater[2353]: [2025-12-06 12:05:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Dec 06 12:05:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Dec 06 12:05:07 volumio systemd[1]: volumio.service: Consumed 46.701s CPU time.
Dec 06 12:05:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 12:05:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 12:05:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20959.
Dec 06 12:05:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 12:05:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Dec 06 12:05:07 volumio systemd[1]: volumio.service: Consumed 46.701s CPU time.
Dec 06 12:05:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 06 12:05:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 12:05:09 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:09 volumio volumio[1497]: info: ----- Volumio3 ----
Dec 06 12:05:09 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:09 volumio volumio[1497]: info: ----- System startup ----
Dec 06 12:05:09 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:09 volumio volumio[1497]: info: MYVOLUMIO Environment detected
Dec 06 12:05:10 volumio volumio[1497]: info: Plugin folders cleanup
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning into folder /volumio/app/plugins/
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category audio_interface
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category miscellanea
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category music_service
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category plugins.json
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category system_controller
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category user_interface
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning into folder /data/plugins/
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category audio_interface
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category music_service
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category system_controller
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category system_hardware
Dec 06 12:05:10 volumio volumio[1497]: info: Scanning category user_interface
Dec 06 12:05:10 volumio volumio[1497]: info: Plugin folders cleanup completed
Dec 06 12:05:10 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:10 volumio volumio[1497]: info: ----- Core plugins startup ----
Dec 06 12:05:10 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:10 volumio volumio[1497]: info: Loading plugins from folder /volumio/app/plugins/
Dec 06 12:05:10 volumio volumio[1497]: info: Adding plugin upnp to MyMusic Plugins
Dec 06 12:05:10 volumio volumio[1497]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 06 12:05:10 volumio volumio[1497]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 06 12:05:10 volumio volumio[1497]: info: Loading plugins from folder /data/plugins/
Dec 06 12:05:10 volumio volumio[1497]: info: Loading plugin "system"...
Dec 06 12:05:10 volumio volumio[1497]: info: Loading plugin "appearance"...
Dec 06 12:05:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72.
Dec 06 12:05:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:10 volumio go-librespot[1524]: go-librespot daemon starting...
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=debug msg="app state loaded"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-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 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-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 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-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 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=info msg="zeroconf server listening on port 41455"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=debug msg="obtained new client token: AABiiSElGNiv84UQx1UkSdkqpgF7x7qgdhwaHsX9KsUFGSd5KnVtgJAbUHY3w4A43vvLW6L1Z/LQ2S5TLl7lcxHvnKCjtI6unoo9oUT8azDfdQgB2XDZ/MsIWEE0QZ3oLxdncYlAPuQRsG1QdgIXCzuTL8YX8XbUKCYhJdjgxe6bObWLWOwyLUEwR/sO1jUGtZe3YP5tHP395Q2EgqMmoBn+RH9F2EXP9zp9vsfmZAXAwKSSqvA3V2ZqvA=="
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-06:00" level=debug msg="completed challenge"
Dec 06 12:05:10 volumio go-librespot[1525]: time="2025-12-06T12:05:10-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 06 12:05:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "network"...
Dec 06 12:05:11 volumio volumio[1497]: info: Refreshing Cached IP Addresses
Dec 06 12:05:11 volumio sudo[1535]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 12:05:11 volumio sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:11 volumio sudo[1537]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "services"...
Dec 06 12:05:11 volumio sudo[1537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "alsa_controller"...
Dec 06 12:05:11 volumio sudo[1535]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:11 volumio sudo[1537]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:11 volumio sudo[1545]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 06 12:05:11 volumio sudo[1545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:11 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "wizard"...
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "networkfs"...
Dec 06 12:05:11 volumio volumio[1497]: info: Starting Udev Watcher for removable devices
Dec 06 12:05:11 volumio volumio[1497]: info: Ignoring mount for partition: boot
Dec 06 12:05:11 volumio volumio[1497]: info: Ignoring mount for partition: volumio
Dec 06 12:05:11 volumio volumio[1497]: info: Ignoring mount for partition: volumio_data
Dec 06 12:05:11 volumio volumio[1497]: info: Mounting Device Wikipedia
Dec 06 12:05:11 volumio sudo[1575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Dec 06 12:05:11 volumio sudo[1575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:11 volumio sudo[1575]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:11 volumio volumio[1497]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Dec 06 12:05:11 volumio volumio[1497]: dmesg(1) may have more information after failed mount system call.
Dec 06 12:05:11 volumio volumio[1497]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Dec 06 12:05:11 volumio volumio[1497]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Dec 06 12:05:11 volumio volumio[1497]: dmesg(1) may have more information after failed mount system call.
Dec 06 12:05:11 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "volumio_command_line_client"...
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "upnp"...
Dec 06 12:05:11 volumio volumio[1497]: info: [1765044311573] Starting Upmpd Daemon
Dec 06 12:05:11 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "my_music"...
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "mpd"...
Dec 06 12:05:11 volumio sudo[1545]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:11 volumio volumio[1497]: info: Loading plugin "upnp_browser"...
Dec 06 12:05:12 volumio volumio-remote-updater[2353]: [2025-12-06 12:05:12] [connect] Successful connection
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "alarm-clock"...
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "airplay_emulation"...
Dec 06 12:05:13 volumio volumio[1497]: info: Starting Shairport Sync
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "last_100"...
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "webradio"...
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "i2s_dacs"...
Dec 06 12:05:13 volumio volumio[1497]: info: I2S DAC not set, start Auto-detection
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "volumiodiscovery"...
Dec 06 12:05:13 volumio volumio[1497]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:05:13 volumio volumio[1497]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:05:13 volumio volumio[1497]: *** WARNING *** For more information see
Dec 06 12:05:13 volumio volumio[1497]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:05:13 volumio volumio[1497]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:05:13 volumio node[1497]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:05:13 volumio volumio[1497]: *** WARNING *** For more information see
Dec 06 12:05:13 volumio node[1497]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:05:13 volumio node[1497]: *** WARNING *** For more information see
Dec 06 12:05:13 volumio node[1497]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 12:05:13 volumio node[1497]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 12:05:13 volumio node[1497]: *** WARNING *** For more information see
Dec 06 12:05:13 volumio volumio[1497]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 06 12:05:13 volumio volumio[1497]: info: Discovery: Started advertising with name: Volumio
Dec 06 12:05:13 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 12:05:13 volumio volumio[1497]: info: Loading plugin "bandcamp"...
Dec 06 12:05:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73.
Dec 06 12:05:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:14 volumio go-librespot[1583]: go-librespot daemon starting...
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=debug msg="app state loaded"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-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 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-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 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-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 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=info msg="zeroconf server listening on port 38701"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=debug msg="obtained new client token: AAAgWGX/YBCkgSI4e3iEthNyN084fPtAWZyPCeMlZ0Lf627t5ywZCz/MK5mZYWLJzde4Zzcfh+PkfxmlnG4WVvdKb6qi4Iz4yo5flGtpUtSqBuw/1ZemxqIE4RWcrAsrjithHMmCjxRs8qpusJ9qe8M3Ik9uFSOIejJfk2x4JbxZ5/kOdxBe/acZRNOvDmaINiIEBLC/NXEuCoVGIK0ZwI6gKa7exVAghZmIHyv7uhh9A5g3q3X1X+BB7w=="
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-06:00" level=debug msg="completed challenge"
Dec 06 12:05:14 volumio go-librespot[1584]: time="2025-12-06T12:05:14-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 06 12:05:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:15 volumio volumio[1497]: info: Plugin calmradio is not enabled
Dec 06 12:05:15 volumio volumio[1497]: info: Loading plugin "soundcloud"...
Dec 06 12:05:15 volumio volumio[1497]: info: Loading plugin "spop"...
Dec 06 12:05:16 volumio volumio[1497]: info: Loading plugin "squeezelite_mc"...
Dec 06 12:05:17 volumio volumio[1497]: info: Loading plugin "youtube2"...
Dec 06 12:05:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74.
Dec 06 12:05:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:17 volumio go-librespot[1591]: go-librespot daemon starting...
Dec 06 12:05:17 volumio go-librespot[1592]: time="2025-12-06T12:05:17-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:17 volumio go-librespot[1592]: time="2025-12-06T12:05:17-06:00" level=debug msg="app state loaded"
Dec 06 12:05:17 volumio go-librespot[1592]: time="2025-12-06T12:05:17-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:17 volumio go-librespot[1592]: time="2025-12-06T12:05:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:17 volumio volumio[1497]: info: Loading plugin "ytcr"...
Dec 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-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 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-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 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-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 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-06:00" level=info msg="zeroconf server listening on port 36947"
Dec 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-06:00" level=debug msg="obtained new client token: AADQl7E5bbNCzKeDkXpG9pthDahZA+lzIzXAXZ0sgXx1yVRcMMzaxLsZ7NuNMAplYzdjCe5VviXnd+iIGj9d/69j9UbfXjXnyyzt/XX5zNDKi60GzMwPPftc+rJHAiX2iHtuKvjC8bQyEGpvpH/0oQusyJG6dEozPn+F2X/iWGqsIYJb2cl5E0Na5BGQmrse+z1c+jL3iYXumiIymt5T4u97lg+tkmqtyg8lPkBR3EdUDjtbNMb1vPU="
Dec 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-06:00" level=debug msg="completed challenge"
Dec 06 12:05:18 volumio go-librespot[1592]: time="2025-12-06T12:05:18-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 06 12:05:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "ytmusic"...
Dec 06 12:05:19 volumio volumio[1497]: info: Plugin now_playing is not enabled
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "outputs"...
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "albumart"...
Dec 06 12:05:19 volumio volumio[1497]: info: Plugin example_plugin is not enabled
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "inputs"...
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "updater_comm"...
Dec 06 12:05:19 volumio volumio[1497]: info: Plugin mpdemulation is not enabled
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "rest_api"...
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "websocket"...
Dec 06 12:05:19 volumio volumio[1497]: info: Starting Socket.io Server version 1.7.4
Dec 06 12:05:19 volumio volumio[1497]: info: Plugin fusiondsp is not enabled
Dec 06 12:05:19 volumio volumio[1497]: info: Plugin mpdoutput is not enabled
Dec 06 12:05:19 volumio volumio[1497]: info: Plugin RoonBridge is not enabled
Dec 06 12:05:19 volumio volumio[1497]: info: Loading plugin "podcast"...
Dec 06 12:05:20 volumio volumio[1497]: info: ControllerPodcast::constructor
Dec 06 12:05:20 volumio volumio[1497]: info: Loading plugin "volusonic"...
Dec 06 12:05:20 volumio volumio[1599]: Forking 3 albumart workers
Dec 06 12:05:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75.
Dec 06 12:05:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:21 volumio volumio[1610]: Starting albumart workers
Dec 06 12:05:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:21 volumio go-librespot[1653]: go-librespot daemon starting...
Dec 06 12:05:21 volumio volumio[1497]: info: Applying required configuration parameters for plugin volusonic
Dec 06 12:05:21 volumio volumio[1497]: info: Loading plugin "backup_restore"...
Dec 06 12:05:21 volumio go-librespot[1654]: time="2025-12-06T12:05:21-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:21 volumio go-librespot[1654]: time="2025-12-06T12:05:21-06:00" level=debug msg="app state loaded"
Dec 06 12:05:21 volumio go-librespot[1654]: time="2025-12-06T12:05:21-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:21 volumio go-librespot[1654]: time="2025-12-06T12:05:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:21 volumio volumio[1609]: Starting albumart workers
Dec 06 12:05:21 volumio volumio[1611]: Starting albumart workers
Dec 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-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 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-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 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-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 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-06:00" level=info msg="zeroconf server listening on port 43005"
Dec 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-06:00" level=debug msg="obtained new client token: AACo0wgBrLgqhAHouBgFO3ZcbkOlxCQAB7ZMxdZpxfDpjPXjVe4a/5OKznBrYMSRQ21uxf3H4BorcAq730uD2zIXsuP7aGidCUXwUbduJdNpmcCe2m7/ZqH6yabX/kAQVsBsXVwYMEl55Etq+s0s6inuqE58WuIUq8tl25NyOSpLWC9ifYwJT4hAMUJZczxHVckt+35lJa2I/7VVk+wrdJKm+83Czf7FYjQl7MDMbreK0kz5n2QkQGPiFA=="
Dec 06 12:05:22 volumio volumio[1497]: info: Applying required configuration parameters for plugin backup_restore
Dec 06 12:05:22 volumio volumio[1497]: info: Plugin rpi_eeprom_config is not enabled
Dec 06 12:05:22 volumio volumio[1497]: info: Plugin rpi_eeprom_updater is not enabled
Dec 06 12:05:22 volumio volumio[1497]: info: Loading plugin "scheduledrestart"...
Dec 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-06:00" level=debug msg="completed challenge"
Dec 06 12:05:22 volumio go-librespot[1654]: time="2025-12-06T12:05:22-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 06 12:05:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:22 volumio volumio[1497]: info: Applying required configuration parameters for plugin scheduledrestart
Dec 06 12:05:22 volumio volumio[1497]: info: Plugin Bluetoothremote is not enabled
Dec 06 12:05:22 volumio volumio[1497]: info: Plugin music_services_shield is not enabled
Dec 06 12:05:22 volumio volumio[1497]: info: Loading plugin "Systeminfo"...
Dec 06 12:05:22 volumio volumio[1497]: info: Plugin peppymeterbasic is not enabled
Dec 06 12:05:22 volumio volumio[1497]: info: Loading plugin "peppyspectrum"...
Dec 06 12:05:23 volumio volumio[1497]: info: Loading i18n strings for locale en
Dec 06 12:05:23 volumio volumio[1497]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Dec 06 12:05:23 volumio volumio[1497]: Updating browse sources language
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::initPlayerControls
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: Express server listening on port 3000
Dec 06 12:05:23 volumio volumio[1497]: [Metrics] WebUI: 14s 781.00ms
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::resetVolumioState
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::getcurrentVolume
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:23 volumio sudo[1685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 12:05:23 volumio sudo[1685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:23 volumio sudo[1685]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:23 volumio sudo[1687]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 12:05:23 volumio sudo[1687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:23 volumio sudo[1687]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:23 volumio volumio[1497]: info: Volumio Network Manager: Network status updated: 1
Dec 06 12:05:23 volumio volumio[1497]: info: VolumeController:: Volume=86 Mute =false
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::pushState
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioPushState
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::updateTrackBlock
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrackBlock
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 12:05:23 volumio volumio[1497]: info: Reloading queue from file
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::setRepeat null single undefined
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::pushState
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioPushState
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::setRandom null
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::pushState
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioPushState
Dec 06 12:05:23 volumio volumio[1497]: info: Setting Device type: Raspberry PI
Dec 06 12:05:23 volumio volumio[1497]: info: VolumeController:: Volume=86 Mute =false
Dec 06 12:05:23 volumio volumio[1497]: info: CoreStateMachine::pushState
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioPushState
Dec 06 12:05:23 volumio volumio[1497]: info: Completed loading Core Plugins
Dec 06 12:05:23 volumio sudo[1700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 06 12:05:23 volumio volumio[1497]: info: Preparing to generate the ALSA configuration file
Dec 06 12:05:23 volumio sudo[1700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:23 volumio sudo[1700]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:23 volumio volumio[1497]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Dec 06 12:05:23 volumio volumio[1497]: info: Discovery: Found device Volumio
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:23 volumio volumio[1497]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954
Dec 06 12:05:23 volumio volumio[1497]: info: Discovery: Found device Volumio
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:23 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:23 volumio volumio[1497]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Dec 06 12:05:23 volumio volumio[1497]: info: Reading ALSA contributions from plugins.
Dec 06 12:05:23 volumio volumio[1497]: info: Upmpdcli Daemon Started
Dec 06 12:05:23 volumio volumio[1497]: info: Asound.conf file unchanged, so no further update is needed
Dec 06 12:05:23 volumio volumio[1497]: info: Output device has changed, restarting MPD
Dec 06 12:05:23 volumio volumio[1497]: info: Output device has changed, restarting Shairport Sync
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:23 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:23 volumio sudo[1703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 12:05:23 volumio sudo[1703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:24 volumio sudo[1703]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:24 volumio sudo[1705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 12:05:24 volumio sudo[1705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:24 volumio volumio[1497]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:05:24 volumio volumio[1497]: info: ___________ START PLUGINS ___________
Dec 06 12:05:24 volumio volumio[1497]: info: ControllerMpd::onStart: Initializing MPD
Dec 06 12:05:24 volumio volumio[1497]: info: Creating MPD Configuration file
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324053] CoreMusicLibrary::Adding element Media Servers
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio sudo[1713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 12:05:24 volumio sudo[1713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 12:05:24 volumio sudo[1715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 12:05:24 volumio sudo[1713]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:24 volumio sudo[1715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:24 volumio volumio[1497]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:24 volumio volumio[1497]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324170] CoreMusicLibrary::Adding element Last_100
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324174] CoreMusicLibrary::Adding element Webradio
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio systemd[1]: mpd.service: Deactivated successfully.
Dec 06 12:05:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 12:05:24 volumio systemd[1]: mpd.service: Consumed 4.571s CPU time.
Dec 06 12:05:24 volumio systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 12:05:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 12:05:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:05:24 volumio volumio[1497]: info: Initializing BBC Radios
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324255] CoreMusicLibrary::Adding element Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324273] CoreMusicLibrary::Adding element SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: info: Creating Spotify config file
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:24 volumio sudo[1741]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 12:05:24 volumio sudo[1741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 12:05:24 volumio sudo[1741]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:24 volumio volumio-remote-updater[2353]: [2025-12-06 12:05:24] [connect] Successful connection
Dec 06 12:05:24 volumio volumio[1497]: info: [squeezelite_mc] Starting proxy server...
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324640] CoreMusicLibrary::Adding element YouTube2
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324662] CoreMusicLibrary::Adding element YouTube Music
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube Music
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324673] CoreMusicLibrary::Adding element Podcast
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube Music
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Podcast
Dec 06 12:05:24 volumio volumio[1497]: info: Loading i18n strings for locale en
Dec 06 12:05:24 volumio volumio[1497]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Dec 06 12:05:24 volumio volumio[1497]: Updating browse sources language
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube Music
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Podcast
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube Music
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Podcast
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:24 volumio volumio[1497]: info: [1765044324721] CoreMusicLibrary::Adding element Volusonic
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source YouTube Music
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Podcast
Dec 06 12:05:24 volumio volumio[1497]: Cannot find translation for source Volusonic
Dec 06 12:05:24 volumio volumio[1497]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Dec 06 12:05:24 volumio volumio[1497]: info: Volumio Calling Home
Dec 06 12:05:24 volumio volumio[1497]: info: [squeezelite_mc] Proxy server started on port 39707
Dec 06 12:05:24 volumio volumio[1497]: info: Preparing to generate the ALSA configuration file
Dec 06 12:05:24 volumio volumio[1497]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 12:05:24 volumio volumio[1497]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Dec 06 12:05:24 volumio volumio[1497]: info: Reading ALSA contributions from plugins.
Dec 06 12:05:25 volumio volumio[1497]: info: MPD Permissions set
Dec 06 12:05:25 volumio volumio[1497]: info: MPD Permissions set
Dec 06 12:05:25 volumio volumio-remote-updater[2353]: [2025-12-06 12:05:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765044324 101
Dec 06 12:05:25 volumio volumio[1497]: 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 06 12:05:25 volumio volumio[1497]: info: Spotify config file written
Dec 06 12:05:25 volumio sudo[1750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 06 12:05:25 volumio sudo[1750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:25 volumio volumio[1497]: 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 06 12:05:25 volumio volumio[1497]: info: VolumeController:: Volume=86 Mute =false
Dec 06 12:05:25 volumio volumio[1497]: info: CoreStateMachine::pushState
Dec 06 12:05:25 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::volumioPushState
Dec 06 12:05:25 volumio volumio[1497]: info: [squeezelite_mc] Server discovery started
Dec 06 12:05:25 volumio volumio[1497]: info: [squeezelite_mc] Player finder started
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true
Dec 06 12:05:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:25 volumio go-librespot[1752]: go-librespot daemon starting...
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio sudo[1750]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=debug msg="app state loaded"
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: No need to fix Spotify hosts
Dec 06 12:05:25 volumio volumio[1497]: 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 06 12:05:25 volumio volumio[1497]: info: Volumio called home
Dec 06 12:05:25 volumio volumio[1497]: 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 06 12:05:25 volumio volumio[1497]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Dec 06 12:05:25 volumio volumio[1497]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Dec 06 12:05:25 volumio volumio[1497]: 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 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-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 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-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 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-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 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=info msg="zeroconf server listening on port 35559"
Dec 06 12:05:25 volumio volumio[1497]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 06 12:05:25 volumio volumio[1497]: SPOTIFY: BQBI0b0Ne4vdg8B5O-7rnLNFdbRZaZZ3E25HWfoUg9fPXMJtJSzZ45acGGspc51Esb45GdfKy2lfDry-vInHQgO5o7_3S7DdcpkaE5IcNtGLl5TfMVz2imbVp43K9qDJaft3bchzI3Ga_oxytVyDGJoaTWVocZv102doKeXZ5d5VIscvLxNp9L_XXN2beyQIev13l81GuWp83aRWpA1YjfP6qkJOfyvZvl_Jr0Y
Dec 06 12:05:25 volumio volumio[1497]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 06 12:05:25 volumio volumio[1497]: info: New Spotify access token = BQBI0b0Ne4vdg8B5O-7rnLNFdbRZaZZ3E25HWfoUg9fPXMJtJSzZ45acGGspc51Esb45GdfKy2lfDry-vInHQgO5o7_3S7DdcpkaE5IcNtGLl5TfMVz2imbVp43K9qDJaft3bchzI3Ga_oxytVyDGJoaTWVocZv102doKeXZ5d5VIscvLxNp9L_XXN2beyQIev13l81GuWp83aRWpA1YjfP6qkJOfyvZvl_Jr0Y
Dec 06 12:05:25 volumio volumio[1497]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 06 12:05:25 volumio volumio[1497]: info: Starting Shairport Sync
Dec 06 12:05:25 volumio volumio[1497]: info: Starting Shairport Sync
Dec 06 12:05:25 volumio volumio[1497]: info: Starting Shairport Sync
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=debug msg="obtained new client token: AACsZfa/fzXy8qjVtukNSk3gcsl5CeIrIcGMDGDIKJhDUoqooaUwBdAW7CCKVvGU6Jfe+cEPQWFL+ZGRjCEU1UcLXcgN4BDWwS8GzmTP0Ec0GiQItEVIQvhnJVIews7pcFPqVO1MU7XZaGDsZ/ToSiVV3GLzfm95mk8p1IMYSlqIAuthCj7ZblpY4hsDtR9dvSVCafeTUM6rjHITmKEqIj/7dX8Z2kqxiiiPt6lw79ykUNBq1Ub/sc/yCQ=="
Dec 06 12:05:25 volumio sudo[1776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:05:25 volumio sudo[1776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio sudo[1778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:05:25 volumio sudo[1778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio sudo[1774]: 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 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:25 volumio volumio[1497]: info: Asound.conf file unchanged, so no further update is needed
Dec 06 12:05:25 volumio volumio[1497]: info: Output device has changed, restarting MPD
Dec 06 12:05:25 volumio sudo[1780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:05:25 volumio sudo[1780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio sudo[1774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio volumio[1497]: info: Output device has changed, restarting Shairport Sync
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:25 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-06:00" level=debug msg="completed challenge"
Dec 06 12:05:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 12:05:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 12:05:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:05:25 volumio systemd[1]: shairport-sync.service: Consumed 1.752s CPU time.
Dec 06 12:05:25 volumio volumio[1497]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 12:05:25 volumio sudo[1774]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:25 volumio sudo[1786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 12:05:25 volumio go-librespot[1754]: time="2025-12-06T12:05:25-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 06 12:05:25 volumio sudo[1786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio sudo[1786]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:25 volumio sudo[1788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 12:05:25 volumio sudo[1788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:05:25 volumio sudo[1776]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:25 volumio sudo[1778]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 12:05:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 12:05:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:05:26 volumio volumio[1497]: info: MPD Permissions set
Dec 06 12:05:26 volumio volumio[1497]: info: Shairport-Sync Started
Dec 06 12:05:26 volumio volumio[1497]: Error adding Membership: Error: addMembership EINVAL
Dec 06 12:05:26 volumio volumio[1497]: info: Shairport-Sync Started
Dec 06 12:05:26 volumio volumio[1497]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Dec 06 12:05:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:05:26 volumio sudo[1780]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:26 volumio systemd[1]: mpd.service: Deactivated successfully.
Dec 06 12:05:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 12:05:26 volumio systemd[1]: mpd.service: Consumed 1.622s CPU time.
Dec 06 12:05:26 volumio sudo[1816]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Dec 06 12:05:26 volumio sudo[1816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:26 volumio systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 12:05:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 12:05:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 12:05:26 volumio sudo[1816]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:26 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 12:05:26 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 12:05:26 volumio volumio[1497]: 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 06 12:05:26 volumio volumio[1497]: info: Shairport-Sync Started
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:26 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:26 volumio volumio[1497]: info: Starting Shairport Sync
Dec 06 12:05:26 volumio volumio[1497]: 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 06 12:05:26 volumio volumio[1497]: info: Spotify Successfully logged in
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 12:05:26 volumio volumio[1497]: info: [1765044326420] CoreMusicLibrary::Adding element Spotify
Dec 06 12:05:26 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source Bandcamp Discover
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source SoundCloud
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source YouTube2
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source YouTube Music
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source Podcast
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source Volusonic
Dec 06 12:05:26 volumio volumio[1497]: Cannot find translation for source Spotify
Dec 06 12:05:26 volumio sudo[1819]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 12:05:26 volumio sudo[1819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 12:05:26 volumio sudo[1836]: 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 06 12:05:26 volumio sudo[1836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:26 volumio sudo[1843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 12:05:26 volumio sudo[1843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:26 volumio sudo[1836]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:26 volumio sudo[1819]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:26 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Dec 06 12:05:26 volumio sudo[1851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Dec 06 12:05:26 volumio sudo[1851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 12:05:26 volumio systemd[1]: Reloading.
Dec 06 12:05:26 volumio volumio[1497]: info: [squeezelite_mc] Notification listener started
Dec 06 12:05:26 volumio volumio[1497]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180)
Dec 06 12:05:27 volumio volumio[1497]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"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"}},{"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"}}]
Dec 06 12:05:27 volumio volumio[1497]: 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 06 12:05:27 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:27 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:27 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 12:05:27 volumio volumio[1497]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 12:05:28 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 06 12:05:28 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 06 12:05:28 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:28 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:28 volumio sudo[1851]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 12:05:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:05:28 volumio volumio[1497]: info: go-librespot daemon successfully initialized
Dec 06 12:05:28 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:28 volumio sudo[1871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:28 volumio sudo[1871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 12:05:28 volumio sudo[1843]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:28 volumio volumio[1497]: info: Shairport-Sync Started
Dec 06 12:05:28 volumio sudo[1871]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:28 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Dec 06 12:05:28 volumio sudo[1888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Dec 06 12:05:28 volumio sudo[1888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:28 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Dec 06 12:05:28 volumio volumio[1497]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect'
Dec 06 12:05:28 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:28 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76.
Dec 06 12:05:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:29 volumio go-librespot[1891]: go-librespot daemon starting...
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=debug msg="app state loaded"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:29 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Dec 06 12:05:29 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Dec 06 12:05:29 volumio sudo[1888]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-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 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-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 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-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 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=info msg="zeroconf server listening on port 35953"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=debug msg="obtained new client token: AABP68EhuHnQCvV3mIE6/5gcJpyHXWqdA0ElbNGe8GA4k//ngLYxtZkwnfiaj8F/55YunaUvqbRrVrAGJyFZZjgQEJM7egqDInofAauV5HuvOIYoYr+lEEXt3831mPZ2XC3ohjrtStAHvYpjOURtT2ve/430QhwyEIHuIQYkgccCxv0KA77oAc7VjgZ6iYxzjo9ZUhWD4NZQ5ZsmVGPcMuMTDDyBEqQhQ+mKDNiszxOWQYdLRjNlRaSfZQ=="
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-06:00" level=debug msg="completed challenge"
Dec 06 12:05:29 volumio go-librespot[1892]: time="2025-12-06T12:05:29-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 06 12:05:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:29 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:29 volumio sudo[1901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:29 volumio sudo[1901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:29 volumio sudo[1901]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:29 volumio volumio[1497]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Dec 06 12:05:29 volumio sudo[1905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Dec 06 12:05:29 volumio sudo[1905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:29 volumio sudo[1905]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:29 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Dec 06 12:05:29 volumio sudo[1908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Dec 06 12:05:29 volumio sudo[1908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:29 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Dec 06 12:05:29 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Dec 06 12:05:30 volumio sudo[1908]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:30 volumio volumio[1497]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect'
Dec 06 12:05:30 volumio volumio[1497]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180)
Dec 06 12:05:30 volumio volumio[1497]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"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"}},{"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"}}]
Dec 06 12:05:30 volumio volumio[1497]: 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 06 12:05:30 volumio mpd[1849]: 2025-12-06T12:05:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 12:05:30 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 12:05:30 volumio sudo[1715]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:30 volumio sudo[1705]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:30 volumio sudo[1788]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:30 volumio volumio[1497]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 12:05:30 volumio volumio[1497]: assert.ok(self.idling)
Dec 06 12:05:30 volumio volumio[1497]: error: The expression evaluated to a falsy value:
Dec 06 12:05:30 volumio volumio[1497]: assert.ok(self.idling)
Dec 06 12:05:30 volumio volumio[1497]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 12:05:30 volumio volumio[1497]: assert.ok(self.idling)
Dec 06 12:05:30 volumio volumio[1497]: error: The expression evaluated to a falsy value:
Dec 06 12:05:30 volumio volumio[1497]: assert.ok(self.idling)
Dec 06 12:05:30 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:30 volumio volumio[1497]: info: MPD running with PID1849
Dec 06 12:05:30 volumio volumio[1497]: ,establishing connection
Dec 06 12:05:30 volumio volumio[1497]: error: updateQueue error: null
Dec 06 12:05:30 volumio volumio[1497]: error: updateQueue error: null
Dec 06 12:05:30 volumio sudo[1919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:30 volumio sudo[1919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:30 volumio sudo[1919]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:31 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:31 volumio sudo[1922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:31 volumio sudo[1922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:31 volumio sudo[1922]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:31 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:31 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:31 volumio volumio[1497]: info: Initializing connection to go-librespot Websocket
Dec 06 12:05:31 volumio volumio[1497]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:05:31 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:31 volumio sudo[1939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:31 volumio sudo[1939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:31 volumio sudo[1939]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:32 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:32 volumio sudo[1945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:32 volumio sudo[1945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:32 volumio sudo[1945]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77.
Dec 06 12:05:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:32 volumio go-librespot[1947]: go-librespot daemon starting...
Dec 06 12:05:32 volumio go-librespot[1948]: time="2025-12-06T12:05:32-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:32 volumio go-librespot[1948]: time="2025-12-06T12:05:32-06:00" level=debug msg="app state loaded"
Dec 06 12:05:32 volumio go-librespot[1948]: time="2025-12-06T12:05:32-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:32 volumio go-librespot[1948]: time="2025-12-06T12:05:32-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:32 volumio volumio[1497]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Dec 06 12:05:32 volumio sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Dec 06 12:05:32 volumio sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:32 volumio sudo[1955]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:32 volumio volumio[1497]: info: Completed starting Core Plugins
Dec 06 12:05:33 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:33 volumio volumio[1497]: info: ----- MyVolumio plugins startup ----
Dec 06 12:05:33 volumio volumio[1497]: info: -------------------------------------------
Dec 06 12:05:33 volumio volumio[1497]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-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 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-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 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-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 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-06:00" level=info msg="zeroconf server listening on port 41389"
Dec 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-06:00" level=debug msg="obtained new client token: AADMgGFV1TKdy9dqBxtU9svcheQ4tK/TNLQKusYM0fm7yfEL1nAI58p0gC0QGtVEpWQZNZFvY4yzt9SK3bAjgFzBThw+3R/JfFYjJjOTNbDavQwIiWRh8Yt4+7kn02m5VvNu7kmkD5lIKVB3tXWyqHjTlqzMmnEKviY18vOfhz4b8BMhcE1I8Qf6KOvTqB+aAkSpDrbX87GLBbWVS0MEFxHqMxNz10v5STgOu94eoO+dbiB6iAuu6Is="
Dec 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-06:00" level=debug msg="completed challenge"
Dec 06 12:05:33 volumio go-librespot[1948]: time="2025-12-06T12:05:33-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 06 12:05:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:33 volumio sudo[1960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 12:05:33 volumio sudo[1960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:33 volumio sudo[1962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 12:05:33 volumio sudo[1962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:33 volumio sudo[1965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 12:05:33 volumio sudo[1965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 12:05:33 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 12:05:33 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 12:05:33 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 12:05:33 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 12:05:33 volumio sudo[1962]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:33 volumio sudo[1965]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:33 volumio sudo[1960]: pam_unix(sudo:session): session closed for user root
Dec 06 12:05:33 volumio mpd_monitor.sh[1968]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 12:05:33 volumio volumio[1497]: info: Successfully started MPD Monitor
Dec 06 12:05:33 volumio volumio[1497]: info: Successfully started MPD Monitor
Dec 06 12:05:33 volumio volumio[1497]: info: Successfully started MPD Monitor
Dec 06 12:05:34 volumio volumio[1497]: info: Initializing connection to go-librespot Websocket
Dec 06 12:05:34 volumio volumio[1497]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 12:05:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78.
Dec 06 12:05:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 12:05:36 volumio go-librespot[1972]: go-librespot daemon starting...
Dec 06 12:05:36 volumio go-librespot[1973]: time="2025-12-06T12:05:36-06:00" level=info msg="running go-librespot 0.4.0"
Dec 06 12:05:36 volumio go-librespot[1973]: time="2025-12-06T12:05:36-06:00" level=debug msg="app state loaded"
Dec 06 12:05:36 volumio go-librespot[1973]: time="2025-12-06T12:05:36-06:00" level=debug msg="stored credentials not found"
Dec 06 12:05:36 volumio go-librespot[1973]: time="2025-12-06T12:05:36-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 12:05:38 volumio volumio[1497]: info: Initializing connection to go-librespot Websocket
Dec 06 12:05:38 volumio go-librespot[1973]: time="2025-12-06T12:05:38-06:00" level=debug msg="new websocket client"
Dec 06 12:05:38 volumio volumio[1497]: info: Connection to go-librespot Websocket established
Dec 06 12:05:41 volumio volumio[1497]: info: Getting Spotify volume
Dec 06 12:05:41 volumio volumio[1497]: 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 06 12:05:41 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:41 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:41 volumio volumio[1497]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Dec 06 12:05:41 volumio volumio[1497]: SPOTIFY: SPOTIFY VOLUME undefined
Dec 06 12:05:41 volumio volumio[1497]: SPOTIFY: VOLUMIO VOLUME 86
Dec 06 12:05:41 volumio volumio[1497]: info: Aligning Spotify Volume to Volumio Volume
Dec 06 12:05:41 volumio volumio[1497]: info: CoreCommandRouter::volumioGetState
Dec 06 12:05:41 volumio volumio[1497]: info: CorePlayQueue::getTrack 0
Dec 06 12:05:41 volumio volumio[1497]: info: Setting Spotify Volume from Volumio: 86
Dec 06 12:05:42 volumio volumio[1497]: SPOTIFY: SETTING SPOTIFY VOLUME 86
Dec 06 12:05:42 volumio volumio[1497]: info: Sending Spotify command with payload to local API: /player/volume
Dec 06 12:05:42 volumio go-librespot[1973]: time="2025-12-06T12:05: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 06 12:05:42 volumio go-librespot[1973]: time="2025-12-06T12:05: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 06 12:05:42 volumio go-librespot[1973]: time="2025-12-06T12:05: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 06 12:05:42 volumio go-librespot[1973]: time="2025-12-06T12:05:42-06:00" level=info msg="zeroconf server listening on port 37495"
Dec 06 12:05:42 volumio go-librespot[1973]: time="2025-12-06T12:05:42-06:00" level=debug msg="obtained new client token: AACN8Db4Q6p4mdgyue7qT3V5a5yTohG+5tigX+DumGBUHYjUC9zBDtWwVW92jZml19Ij3S/FDHGg2u9Fp6SGWTtdJL8C+qLGJEAe+K/BtEUOl/Z8p3mcXhvvwb3y/xDN2b9FNvSOhwpchQstlumUlAJJOq0gzM9F/Ahwk7/iGjwu1fph8a7XZuiGmXGUtAutIA/u62NaZSAPfoGyDhvyFtYZRa9ZfMWgIatKAwWWuZT3S4lSMrszRiVQoA=="
Dec 06 12:05:42 volumio go-librespot[1973]: time="2025-12-06T12:05:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Dec 06 12:05:43 volumio go-librespot[1973]: time="2025-12-06T12:05:43-06:00" level=debug msg="completed keyexchange"
Dec 06 12:05:43 volumio go-librespot[1973]: time="2025-12-06T12:05:43-06:00" level=debug msg="completed challenge"
Dec 06 12:05:43 volumio go-librespot[1973]: time="2025-12-06T12:05:43-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 06 12:05:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 12:05:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 12:05:43 volumio volumio[1497]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up
Dec 06 12:05:43 volumio volumio[1497]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 12:05:43 volumio volumio[1497]: Error: socket hang up
Dec 06 12:05:43 volumio volumio[1497]: at connResetException (node:internal/errors:720:14)
Dec 06 12:05:43 volumio volumio[1497]: at Socket.socketOnEnd (node:_http_client:519:23)
Dec 06 12:05:43 volumio volumio[1497]: at Socket.emit (node:events:526:35)
Dec 06 12:05:43 volumio volumio[1497]: at endReadableNT (node:internal/streams/readable:1376:12)
Dec 06 12:05:43 volumio volumio[1497]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Dec 06 12:05:43 volumio volumio[1497]: code: 'ECONNRESET',
Dec 06 12:05:43 volumio volumio[1497]: response: undefined
Dec 06 12:05:43 volumio volumio[1497]: }
Dec 06 12:05:43 volumio volumio[1497]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 12:05:43 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Dec 06 12:05:43 volumio sudo[2029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 12:04'
Dec 06 12:05:43 volumio sudo[2029]: 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"