Aug 30 19:47:00 caramel-cajon volumio[1209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Aug 30 19:47:00 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:47:00 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:47:00 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:00.169+09:00 level=INFO msg="system info for 6d5ebdc0ebf9d69e0d644de155793e69" deviceName=caramel-cajon deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 30 19:47:00 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:00.186+09:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 30 19:47:00 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:47:00 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:47:00 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:47:00 caramel-cajon volumio-remote-updater[681]: Test mode disabled Aug 30 19:47:00 caramel-cajon volumio-remote-updater[681]: Alpha mode disabled Aug 30 19:47:00 caramel-cajon volumio-remote-updater[681]: Alpha legacy test mode disabled Aug 30 19:47:02 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:47:02 caramel-cajon volumio[1209]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 30 19:47:02 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 30 19:47:02 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 19:47:02 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:02.738+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 30 19:47:02 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:02.798+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 30 19:47:02 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:02.799+09:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 30 19:47:02 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:47:03 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 30 19:47:03 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:03 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:03 caramel-cajon go-librespot[2273]: go-librespot daemon starting... Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=debug msg="app state loaded" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:03 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=info msg="zeroconf server listening on port 40789" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=debug msg="obtained new client token: AAGGE43jwPqOSPXXUdvw97juWHdXDpMNnWtklFtK5jfTEPeJc+kQFXrA0/5TvULLuOHpORj/shy7ecn7UcwOFxbxEcICSipLhv+2hQcnFQihxtdL0Q5QcNhcKEbJ/L9d6otNLbTPHIP6xcUO752MK4H/3KgFE9VFMW7rk9VzWCNm/uG8BifEuJ045fJP5ReD5ykR/Qa501tvH40Q4Ee6TOHBNbw+MqSTWPnt9UTiS2vO0gBBTbEQPok3cg==" Aug 30 19:47:03 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:03+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:04 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:04+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:04 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:04+09:00" level=debug msg="completed challenge" Aug 30 19:47:04 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 19:47:04 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:04+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:04 caramel-cajon go-librespot[2274]: time="2026-08-30T19:47:04+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:04 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:04 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:04 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:47:04 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:47:04 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:47:04 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:47:04 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:47:04 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:47:04 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:47:05 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 19:47:05 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 19:47:05 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:05.580+09:00 level=INFO msg="enabling local network discovery" Aug 30 19:47:05 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:05.622+09:00 level=INFO msg="enabling BLE discovery" Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 30 19:47:05 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 30 19:47:05 caramel-cajon volumio[1209]: info: Adding plugin bluetooth to MyMusic Plugins Aug 30 19:47:05 caramel-cajon volumio[1209]: info: Adding plugin multiroom to MyMusic Plugins Aug 30 19:47:06 caramel-cajon volumio[1209]: info: Adding plugin metavolumio to MyMusic Plugins Aug 30 19:47:06 caramel-cajon volumio[1209]: info: Adding plugin cd_controller to MyMusic Plugins Aug 30 19:47:06 caramel-cajon volumio[1209]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 30 19:47:06 caramel-cajon volumio[1209]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 30 19:47:06 caramel-cajon volumio[1209]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 30 19:47:06 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 30 19:47:06 caramel-cajon volumio5-onboarding[2251]: time=2026-08-30T19:47:06.865+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 30 19:47:07 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 30 19:47:07 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:07 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:07 caramel-cajon go-librespot[2301]: go-librespot daemon starting... Aug 30 19:47:07 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:07+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:07 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:07+09:00" level=debug msg="app state loaded" Aug 30 19:47:07 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:07+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=info msg="zeroconf server listening on port 37519" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="obtained new client token: AAE41MF4GMI4YtuPAFMP7AlB0vk3XD2pSH12ISOMO8P3ZFCebZJwsP82qcG5Cn7hMsNAZrFGZu6dByryu+p9WQOjWcgdmWyIe4gp9Igv88ZEh1+s8m/cz7RvGOUdjOUeH/hwGfd9EAKzIvDs2KI7KD4ixI6H7Q4fOkqMuCakiVgy4ktHpERXyr7OvISfy+HGPPLz8h3YEmR4HVOadHndE8acr8mDdXjt2FmYUeWbnpezuRfbLu5Ai6aqvQ==" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=debug msg="completed challenge" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:08 caramel-cajon go-librespot[2302]: time="2026-08-30T19:47:08+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:09 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:09 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:12 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 30 19:47:12 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:12 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:12 caramel-cajon go-librespot[2312]: go-librespot daemon starting... Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=debug msg="app state loaded" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=info msg="zeroconf server listening on port 34127" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:12 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:12+09:00" level=debug msg="obtained new client token: AAGeDMSWQ5I1sKJwhIkCEPfP0FvgB1NdCCxSyA61wQzAZu0CD6MAf2YANKtHd9wmvZNLzcnltxznM9dcibB4NoEUozpv6NMjzfHtrJwRSNWgV1NRBbXoO8gz0NXjjS2ZsnGzoG3Uqm7cvymtHQ5ekRCq183jvBa9a5jiEG81qbbSxaZG0FFsVncROLLoXT6nuO12nbYdHyNeWIY014eSDYTNTlkj3CGLvbOoEW1PCENcdC+W9h9l4hhRnA==" Aug 30 19:47:13 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:13+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:13 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:13+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:13 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:13+09:00" level=debug msg="completed challenge" Aug 30 19:47:13 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:13+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:13 caramel-cajon go-librespot[2313]: time="2026-08-30T19:47:13+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:13 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:13 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:15 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 30 19:47:15 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 30 19:47:15 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:47:15 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:47:16 caramel-cajon volumio[1209]: info: Starting MyVolumio Remote Streaming Endpoints Aug 30 19:47:16 caramel-cajon volumio[1209]: info: MyVolumio login type: Token Aug 30 19:47:16 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 30 19:47:16 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 30 19:47:16 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 30 19:47:16 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:16 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:16 caramel-cajon go-librespot[2336]: go-librespot daemon starting... Aug 30 19:47:16 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:16+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:16 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:16+09:00" level=debug msg="app state loaded" Aug 30 19:47:16 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:16+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=info msg="zeroconf server listening on port 44699" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="obtained new client token: AAGKCo4zduD+n6K1sPWTG+qqHClL9qQneFwOQ0Ta4VBAd7wUSwDsTpudRkn+9pmNTM/PlJW/8lyBRz2cEJVVdIUK8uBladMsB1JW6HJL7UtYnxELRG7IrwiY4Wjp1Ec0QAVw++52xDfChTobV5c0JHIzR6NlS13ZFALORoPkRv8X3Fw2GwmYICgeG1vdj/Pbif5zBcs5OcWxHLE2ZqPL+ANnL9y3DwaebLD0sovrQZawM8hh38/DFvSsqw==" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=debug msg="completed challenge" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:17 caramel-cajon go-librespot[2337]: time="2026-08-30T19:47:17+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:17 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:17 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:20 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 30 19:47:20 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:20 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:20 caramel-cajon go-librespot[2347]: go-librespot daemon starting... Aug 30 19:47:20 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:20+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:20 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:20+09:00" level=debug msg="app state loaded" Aug 30 19:47:20 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:20+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=info msg="zeroconf server listening on port 35595" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="obtained new client token: AAE8s4StmPzaOJe/3ZSwlFDm8XUszPTpV0r0muhCmn0gUD2QWHadzvHNbxhWhn5R/qt/jMqbCvTbyV7UawteqYy/NZYCCuX9WZS9LW1Xix8PS1LY9tqiMqC4Y2rAK9UmjAcnOjR0z5sp85uyhLmxu5LGwl+7StW2fM0zvf+goDz6l0XxM2Ke6NIXK+GQbg6ds8+4IuMDzNB76nUpNuv3nstLQTjX75uDuaa4kNHGEjmBFSCaxCxUIyZhbA==" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=debug msg="completed challenge" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:21 caramel-cajon go-librespot[2348]: time="2026-08-30T19:47:21+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:21 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:21 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:22 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 30 19:47:22 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 30 19:47:22 caramel-cajon volumio[1209]: info: Streaming services startup Aug 30 19:47:22 caramel-cajon volumio[1209]: info: Starting Streaming Daemon Aug 30 19:47:22 caramel-cajon volumio[1209]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 30 19:47:22 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:47:23 caramel-cajon sudo[2358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 19:47:23 caramel-cajon sudo[2358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 19:47:24 caramel-cajon sudo[2358]: pam_unix(sudo:session): session closed for user root Aug 30 19:47:24 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:47:25 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 30 19:47:25 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:25 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:25 caramel-cajon go-librespot[2379]: go-librespot daemon starting... Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=debug msg="app state loaded" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=info msg="zeroconf server listening on port 34749" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:25 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:25+09:00" level=debug msg="obtained new client token: AAF8HQSoOGJQxSBO8MyKOu5O1Js3+42QhyIBHn44Pu6qZo+5sOpdYb6NSRJX2kQuBjtYACegqBicigeIYD75gx7wk2KfW38H7BIWTlPL1JCxpbb1Vrt5x6cUrEJpv8Ilmc2ovdHLwQYCzWmGgmpnDYjD4sQEZenith20xoOzu4g8rVtHwXyyxawkFP91kOwAYr2z/URHkdJJMD7JX75stpZASuxwu/I/2v1Tqrv+SVLXyWImczGNOpujMw==" Aug 30 19:47:26 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:26+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:26 caramel-cajon volumio[1209]: error: Cannot start Volumio Streaming Daemon Aug 30 19:47:26 caramel-cajon volumio[1209]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 19:47:26 caramel-cajon volumio[1209]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 19:47:26 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:26+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:26 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:26+09:00" level=debug msg="completed challenge" Aug 30 19:47:26 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:26+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:26 caramel-cajon go-librespot[2380]: time="2026-08-30T19:47:26+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:26 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:26 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:26 caramel-cajon volumio[1209]: error: MyVolumio Custom Token format not valid, refreshing it Aug 30 19:47:28 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:47:28 caramel-cajon volumio[1209]: info: JP_Radio::Radiko.saveStationLogoCache: https://radiko.jp/v2/static/station/logo/ABCR-KOSHIEN/448x200.png => ABCR-KOSHIEN_logo.png Aug 30 19:47:28 caramel-cajon volumio[1209]: info: JP_Radio::Radiko.getStations: ## COMPLETED 58347ms ## Aug 30 19:47:28 caramel-cajon volumio[1209]: info: JP_Radio::JpRadio.#pgupdate: Updating program listings... Aug 30 19:47:28 caramel-cajon volumio[1209]: info: JP_Radio::RdkProg.updatePrograms: [boot] Aug 30 19:47:28 caramel-cajon volumio[1209]: info: JP_Radio::RdkProg.getPrograms: http://radiko.jp/v3/program/today/JP14.xml Aug 30 19:47:29 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 30 19:47:29 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:29 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:29 caramel-cajon go-librespot[2391]: go-librespot daemon starting... Aug 30 19:47:29 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:29+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:29 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:29+09:00" level=debug msg="app state loaded" Aug 30 19:47:29 caramel-cajon volumio[1209]: info: [yt-cast-receiver] DIAL server listening on port 8098 Aug 30 19:47:29 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:29+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:29 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioRetrievevolume Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=info msg="zeroconf server listening on port 37315" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="obtained new client token: AAEYFAyRrt7kEDTkEPbuJPPYIoyM7+bbCjkmi2hhqBowCQy+RhMgNvhjxrCoM6nTf6RZhLodSolsg86hTvPdu/XvDBIBWO42wRSidNMd4DbmFvT2yTDMjCT/WbRn0kgg/wRmeB9QqpHmYfatM09sxUHBCfOLEilh7AYneugsZHR22mlWmQqiahyVBH8L3BYBG/xkCInGy0TtSiobj3AfeZA1vOduLm2mBOyFuEIJxudiDG4AFTGvTGcrbA==" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=debug msg="completed challenge" Aug 30 19:47:30 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:30+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:30 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:47:31 caramel-cajon go-librespot[2392]: time="2026-08-30T19:47:31+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:31 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:31 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:31 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 19:47:32 caramel-cajon volumio[1209]: info: VolumeController:: Volume=14 Mute =false Aug 30 19:47:32 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:47:32 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:47:32 caramel-cajon volumio[1209]: info: CoreStateMachine::pushState Aug 30 19:47:32 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:47:32 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioPushState Aug 30 19:47:32 caramel-cajon volumio[1209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 30 19:47:33 caramel-cajon volumio[1209]: info: MyVolumio login type: Token Aug 30 19:47:33 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:47:33 caramel-cajon volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 30 19:47:34 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 30 19:47:34 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:34 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:34 caramel-cajon go-librespot[2404]: go-librespot daemon starting... Aug 30 19:47:34 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:34+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:34 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:34+09:00" level=debug msg="app state loaded" Aug 30 19:47:34 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:47:34 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:47:34 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:34+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:34 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=info msg="zeroconf server listening on port 39539" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="obtained new client token: AAHFMLJx5xa5kaidPvD9JAXpT3WS7+wrsXO4ek6kNaKUIOpfWPNTTYQy+3coHszdffk1Fm+73KXBIxVkjyzeWYEaFSFCmZJeDIjbvgF0MOyOvxqg/XW0YNIzb7DTo/QaiX8Hb5jDdty7FOVZ7Fidm1edALa/H4Ln8fuC2Ll5ZsQxh48QxWZNezqFHX+YjXllYn+5r3w2XmpHozSDNzlXA+z5Xkn6XmpHojB4J944VJAjmrU0z8TwjUpLnA==" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="connected to ap-gae2.spotify.com:443" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=debug msg="completed challenge" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:35 caramel-cajon go-librespot[2405]: time="2026-08-30T19:47:35+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:35 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:35 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetBrowseSources Aug 30 19:47:36 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 19:47:37 caramel-cajon volumio[1209]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 30 19:47:37 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:47:38 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:47:39 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 30 19:47:39 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:39 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:39 caramel-cajon go-librespot[2431]: go-librespot daemon starting... Aug 30 19:47:39 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:39+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:39 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:39+09:00" level=debug msg="app state loaded" Aug 30 19:47:39 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:39+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=info msg="zeroconf server listening on port 33045" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="obtained new client token: AAF1WARjMEOQ/DxZjwiv0C0fIAp/3yz0FfLvB5Ban/3vY2LHhKLwwSlbodCabIYZ+JVYDjWzGGtJ0VaQPQj2ts6zC4OAbo0Bmq6Er7tXSDcoopbrk0leLAtnRo0aC8X8n78DxOQMetgEFNRd78HB7PG7JOahIoZDOEdvYTPU1Q6W0s4lHJEzNY9GcNOoj2eDcZ2GkydqpCzHv/F4hslPyseWx/ErW/R3XKR4nAycSi0r0wesuthF2t4ahw==" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=debug msg="completed challenge" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:40 caramel-cajon go-librespot[2432]: time="2026-08-30T19:47:40+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:40 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:40 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:44 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 30 19:47:44 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:44 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:44 caramel-cajon go-librespot[2451]: go-librespot daemon starting... Aug 30 19:47:44 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:44+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:44 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:44+09:00" level=debug msg="app state loaded" Aug 30 19:47:44 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:44+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=info msg="zeroconf server listening on port 46717" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="obtained new client token: AAEFAm2d8KbjtSfU3kv9LGem+m15dc7CrQ4RWcu5NzQZRzQvnWEqKJ148sa7+4cWATqr/F3J6RE7bZ9lwm7EW/AGXM0ne6l1xlaLQTPlf9Lx8hoGXmBGlFrE3485S/1KSmYGgNEfLSZQw7umd7jGR8s4dLRHxoHePJSupRt6/xwvrZfpiorQYaSfj4L+5WsDIvYOZXSiN6bZRhE69Po8E/eSMVDZlVHTAqlVki5EQMHTQrKEZAm6Q2iW0g==" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=debug msg="completed challenge" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:45 caramel-cajon go-librespot[2452]: time="2026-08-30T19:47:45+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:45 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:45 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:49 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 30 19:47:49 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:49 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:49 caramel-cajon go-librespot[2476]: go-librespot daemon starting... Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="app state loaded" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=info msg="zeroconf server listening on port 33365" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="obtained new client token: AAH+Vl09IMnT9Xuo0pQ3nflLnssegDMquGh7qZx8d7CyGZYPW1lITg6Cc/BdTlNmnHrEWtv152LrhtEqr0+4WWUGR05XZuqc0zOQdLXaAXVgS+YtFkRrUy/1FgLX+7ImJvRKWaRGkv7qt2ltvE4Dm3Eb02+rhdqVGrtGDlibt0NeE5ah2gymuIA1MiidKCQHSpuYjrnxYzGiJ+dubrbu1Y4gc7jI/CjRcyrcDQ/98mIQZsQWX0103IHrRg==" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:49 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:49+09:00" level=debug msg="completed challenge" Aug 30 19:47:50 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:50+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:50 caramel-cajon go-librespot[2477]: time="2026-08-30T19:47:50+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:50 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:50 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:51 caramel-cajon volumio[1209]: info: JP_Radio::RdkProg.dbCount: 538 Aug 30 19:47:52 caramel-cajon volumio[1209]: info: JP_Radio::RdkProg.clearOldProgram: Removed 348 documents from DB Aug 30 19:47:52 caramel-cajon volumio[1209]: info: JP_Radio::RdkProg.dbCount: 190 Aug 30 19:47:52 caramel-cajon volumio[1209]: info: JP_Radio::JpRadio.#pgupdate: ## COMPLETED 23902ms} ## Aug 30 19:47:52 caramel-cajon volumio[1209]: info: JP_Radio::JpRadio.#init: ## COMPLETED myInfo=areaId,JP14,areafree,,member_type,,cntStations,16 ## Aug 30 19:47:52 caramel-cajon volumio[1209]: info: JP_Radio::start: Listening on port 9000 Aug 30 19:47:52 caramel-cajon volumio[1209]: info: JP_Radio::addToBrowseSources: pluginName=jp_radio Aug 30 19:47:52 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 30 19:47:52 caramel-cajon volumio[1209]: info: [1788086872740] CoreMusicLibrary::Adding element RADIKO Aug 30 19:47:52 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 19:47:52 caramel-cajon volumio[1209]: Cannot find translation for source YouTube2 Aug 30 19:47:52 caramel-cajon volumio[1209]: Cannot find translation for source Spotify Aug 30 19:47:52 caramel-cajon volumio[1209]: Cannot find translation for source RADIKO Aug 30 19:47:53 caramel-cajon volumio[1209]: info: JP_Radio::onStart: ## COMPLETED 93609ms ## Aug 30 19:47:53 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:47:53 caramel-cajon volumio[1209]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 30 19:47:53 caramel-cajon volumio[1209]: info: Completed starting MyVolumio Plugin Aug 30 19:47:53 caramel-cajon volumio[1209]: [Metrics] CommandRouter: 169s 811.44ms Aug 30 19:47:53 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumiosetStartupVolume Aug 30 19:47:53 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 19:47:53 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:47:53 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 30 19:47:53 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:53 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:53 caramel-cajon volumio[1209]: info: CoreCommandRouter::Close All Modals sent Aug 30 19:47:53 caramel-cajon volumio[1209]: info: CoreCommandRouter::Close All Modals sent Aug 30 19:47:53 caramel-cajon go-librespot[2488]: go-librespot daemon starting... Aug 30 19:47:53 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:53+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:53 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:53+09:00" level=debug msg="app state loaded" Aug 30 19:47:53 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:53+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:47:54 caramel-cajon volumio[1209]: info: MyVolumio token set successfully Aug 30 19:47:54 caramel-cajon volumio[1209]: info: MYVOLUMIO: Adding device Aug 30 19:47:54 caramel-cajon volumio[1209]: info: MYVOLUMIO: Evaluating Server Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=info msg="zeroconf server listening on port 40039" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="obtained new client token: AAH9QMlm4HIry/YC5wV4Oq09U1YOsJhF4urz4//Sk8ZhPXmhEFzheZUAKbihBGxICYPQ/tZKTfNDqXynAOBSLLXON2fKTmWJTFXC+980+cfL4DTYr8MUB6BvIskJczMXRFWpbMDJ6G3l/YWmh3YQwd7nXqorA6MAiqKvGoSPAr/DMh965YripKjxZ72DatNksRWnhCMJBlVk9ms/kkXsKnISvebEKHP2ZfM0BPJc0g6SXQuzhjxTiFRYVA==" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="completed keyexchange" Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=debug msg="completed challenge" Aug 30 19:47:54 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:47:54 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 30 19:47:54 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:54+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:47:54 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 30 19:47:55 caramel-cajon go-librespot[2490]: time="2026-08-30T19:47:55+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:47:55 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:47:55 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:47:56 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 30 19:47:58 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 30 19:47:58 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:58 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:47:58 caramel-cajon go-librespot[2545]: go-librespot daemon starting... Aug 30 19:47:58 caramel-cajon volumio[1209]: info: MyVolumio status changed Aug 30 19:47:58 caramel-cajon volumio[1209]: info: Streaming services startup Aug 30 19:47:58 caramel-cajon volumio[1209]: info: Starting Streaming Daemon Aug 30 19:47:58 caramel-cajon volumio[1209]: info: Removing browser output: myVolumio user plan is not superstar Aug 30 19:47:58 caramel-cajon volumio[1209]: info: Removing audio output: Aug 30 19:47:58 caramel-cajon volumio[1209]: info: Stoppping Tunnel 1 Aug 30 19:47:58 caramel-cajon volumio[1209]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Aug 30 19:47:58 caramel-cajon volumio[1209]: info: FusionDsp - ---- read samplerate from file: 44100 Aug 30 19:47:58 caramel-cajon volumio[1209]: info: camilladsp stopping service pid 1903... Aug 30 19:47:59 caramel-cajon volumio[1209]: grep: /proc/1903/cmdline: binary file matches Aug 30 19:47:59 caramel-cajon volumio[1209]: grep: /proc/1903/cmdline: binary file matches Aug 30 19:47:59 caramel-cajon volumio[1209]: info: camilladsp service terminated, instance 1 Aug 30 19:47:59 caramel-cajon volumio[1209]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 19:47:59 caramel-cajon go-librespot[2549]: time="2026-08-30T19:47:59+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:47:59 caramel-cajon go-librespot[2549]: time="2026-08-30T19:47:59+09:00" level=debug msg="app state loaded" Aug 30 19:48:00 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:00+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:00 caramel-cajon sudo[2552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 30 19:48:00 caramel-cajon sudo[2554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 30 19:48:00 caramel-cajon sudo[2552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 19:48:00 caramel-cajon sudo[2554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=info msg="zeroconf server listening on port 33321" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="obtained new client token: AAGqsFBYiv2F2/wQB1pBXCi2UVk9vVxTxcQML6Ij+4oaJ1mx7vUnM8Jf0X78+0AOT47aCOTdF6S23jZV9HBpXIhhWjMfRlqjPlUtVZ8fEMgCvZExsgfKBG4QVy2s+NP4QEUlsH8i+HRsTZ4qfk/AzQzui+/H+AtZGPv18lR6wGQFMoRyUom+fXlIul7B2shbVwAJPBA/VHy6X3i2CIA9WwofqO6rGzGLy6dybUypnbgiKHU3WIdpFro=" Aug 30 19:48:01 caramel-cajon volumio[1209]: info: camilladsp service started and running in background, instance 1 Aug 30 19:48:01 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=debug msg="completed challenge" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:01 caramel-cajon go-librespot[2549]: time="2026-08-30T19:48:01+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:01 caramel-cajon volumio[1209]: info: Setting Geolocation for MyVolumio to as1 Aug 30 19:48:01 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:01 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:01 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:02 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:02 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:02 caramel-cajon sudo[2552]: pam_unix(sudo:session): session closed for user root Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon 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. Aug 30 19:48:02 caramel-cajon sudo[2554]: pam_unix(sudo:session): session closed for user root Aug 30 19:48:03 caramel-cajon volumio[1209]: info: camilladsp respawn in 100 ms (attempt 1/10) Aug 30 19:48:03 caramel-cajon volumio[1209]: info: BOOT COMPLETED Aug 30 19:48:03 caramel-cajon volumio[1209]: info: Remote SSH Stopped Aug 30 19:48:03 caramel-cajon volumio[1209]: error: Cannot start Volumio Streaming Daemon Aug 30 19:48:03 caramel-cajon volumio[1209]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 30 19:48:03 caramel-cajon volumio[1209]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 30 19:48:03 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: socket hang up Aug 30 19:48:04 caramel-cajon volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 30 19:48:04 caramel-cajon volumio[1209]: info: Updating MyVolumio device info Aug 30 19:48:04 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:05 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:05 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:05 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 30 19:48:05 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:05 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:05 caramel-cajon go-librespot[2595]: go-librespot daemon starting... Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=debug msg="app state loaded" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=info msg="zeroconf server listening on port 44387" Aug 30 19:48:06 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:06+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:07 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:07+09:00" level=debug msg="obtained new client token: AAFl1Mr+JBKTzSfwC9u+ug/+gyCz6EOMZps4PVuDwWz0mxLG+IMgKRJJWQosgwI3UOOzqauUfc2RP/+0A2P1MK8/ubYQ6OZPWonI6ycvnEN898gvxqR0ymmr5BEZ0pq92wReikun/pSeM5bIBh4a3LWWJiMcm8KcKoSrvo+FQ8G0BvZoVdbnVlXbeQQrO+kPwyh76gmz00Q0tWvpJqYOv5kQsbdpGCbk6JVfLbIcZyPKWrxGFGq6TCU=" Aug 30 19:48:07 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:07+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:07 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:07+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:07 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:07+09:00" level=debug msg="completed challenge" Aug 30 19:48:07 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:07+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:07 caramel-cajon go-librespot[2596]: time="2026-08-30T19:48:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:07 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:07 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:09 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:48:09 caramel-cajon volumio[1209]: info: camilladsp respawn in 200 ms (attempt 2/10) Aug 30 19:48:09 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:48:10 caramel-cajon volumio[1209]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 30 19:48:10 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 30 19:48:10 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:10 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:10 caramel-cajon go-librespot[2643]: go-librespot daemon starting... Aug 30 19:48:10 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:10+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:10 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:10+09:00" level=debug msg="app state loaded" Aug 30 19:48:10 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:10+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=info msg="zeroconf server listening on port 44183" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:11 caramel-cajon volumio[1209]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="obtained new client token: AAH1bEYkBn+b8Y8z+z2JNi4Ue0kE/5BhPBXBKWwVfpanv0N51kHkrJ/lVf8nWdSEHykiUAq2i8sGxIfWOBd/7Yw7OxEWxuviw9vHEsFpbd1JGmNwwC7UMnKV/EpggLgF0DvXjPubKlCXqDDa3tINj/Ku9oNqn9JWaDjiHAfm4CqXv3h57y1CkiK3FA6/vPuxNvcqSTknIQBG5xr/pBPVJhWpDI+e15PaTGPK/lCD/vdcLs5/h4vT2Ctb+Q==" Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetVisibleSources Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=debug msg="completed challenge" Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 30 19:48:11 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:48:11 caramel-cajon go-librespot[2644]: time="2026-08-30T19:48:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:11 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:11 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:48:11 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:11 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Listing playlists Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:12 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:48:12 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:48:13 caramel-cajon volumio[1209]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 30 19:48:15 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 30 19:48:15 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:15 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:17 caramel-cajon go-librespot[2704]: go-librespot daemon starting... Aug 30 19:48:21 caramel-cajon volumio[1209]: info: MYVOLUMIO: Adding device Aug 30 19:48:21 caramel-cajon volumio[1209]: info: MYVOLUMIO: Evaluating Server Aug 30 19:48:21 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:48:24 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:24+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:24 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:24+09:00" level=debug msg="app state loaded" Aug 30 19:48:25 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:25+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:25 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:25+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:48:25 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:25+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:48:25 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:25+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:48:25 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:25+09:00" level=info msg="zeroconf server listening on port 45547" Aug 30 19:48:29 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:29+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:31 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:31+09:00" level=debug msg="obtained new client token: AAF98Zgw/psv0jOXWmUOJ/3k6dQmmIjyvP4EEScEruQCgmyvRopxYvgIUQ2Uf9uh3YQ0MlHqZTjuwgoBZZPTTXbPw6pOC8T7GzJqep+BUNHwkb/snJ28XFzIhAGu0/tkjPonTkjbuXRXRj5b/AtcMsxE1jUxu6FoPvrlJz5FaWT5DZWQZU06wINJO84ilIhguVqqnuIwQAn+pgNfedhBKzacMYADJ8fJxF1u91IdtQg4M3wupYPGFSW9oA==" Aug 30 19:48:31 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:31+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:31 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:31+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:31 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:31+09:00" level=debug msg="completed challenge" Aug 30 19:48:31 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:31+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:31 caramel-cajon go-librespot[2709]: time="2026-08-30T19:48:31+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:32 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:32 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:32 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 30 19:48:33 caramel-cajon volumio[1209]: info: Received Get System Version Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 19:48:33 caramel-cajon volumio[1209]: info: Received Get System Info Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 19:48:33 caramel-cajon volumio[1209]: info: Discovery: Getting this device information Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::volumioGetState Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CorePlayQueue::getTrack 0 Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 19:48:33 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 30 19:48:35 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 30 19:48:35 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:35 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:35 caramel-cajon go-librespot[2752]: go-librespot daemon starting... Aug 30 19:48:35 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:35+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:35 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:35+09:00" level=debug msg="app state loaded" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=info msg="zeroconf server listening on port 37973" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="obtained new client token: AAF4Yd3npC320ackolSDmjWoF8MmhimdSYUaSGkAWXkYHUwUriZTXAireGDT1iww6yBWEhTj/3+wdY8/fvvU/q7tS884tgFjO55fPFU41j01XqwOnFyK15PD8g4mcrHFYUYgB+a6nBmE7d+bpKSWQqpKQrx2HKN2VhzaqNZeWvC6Kprkzx7QrVNekEOW5HE4GUDOoGR/21e9xbWBaOTosFhaLLBuxoMH7wF7zsmV0Zg82eXgOJtLlduWug==" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=debug msg="completed challenge" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:36 caramel-cajon go-librespot[2756]: time="2026-08-30T19:48:36+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:36 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:36 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:37 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 30 19:48:37 caramel-cajon volumio[1209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:48:38 caramel-cajon volumio[1209]: info: Setting Geolocation for MyVolumio to as1 Aug 30 19:48:38 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:38 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:38 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:39 caramel-cajon volumio[1209]: info: Updating MyVolumio device info Aug 30 19:48:39 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:39 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:39 caramel-cajon volumio[1209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 19:48:39 caramel-cajon volumio[1209]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 30 19:48:40 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 30 19:48:40 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:40 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:40 caramel-cajon go-librespot[2780]: go-librespot daemon starting... Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="app state loaded" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:40 caramel-cajon volumio[1209]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=info msg="zeroconf server listening on port 44551" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="obtained new client token: AAEurDJ+N1h5TUEhHvZxGmMUF/7cqm2pjw9VIIdaysf7husm/8X1to8iEhd2lD6EP+9p4RltJG1CBLrQ7FKM5As+xn2haIdVVO1yne5xzzRSvOiWkn51UgZjVz3luY2ljmqDM9wBRj69mbVBsbexRkEoivwCxoA3UCDe1FG+Rtl8AyHe0ZURJPqcb4uA5jeSO+/DfbrzvlR8HRRTA3GwQ4SsXHb6jbhn6k3oCvKdetNy1928cgV/pGNCPg==" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="completed challenge" Aug 30 19:48:40 caramel-cajon volumio[1209]: info: Initializing connection to go-librespot Websocket Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=debug msg="new websocket client" Aug 30 19:48:40 caramel-cajon volumio[1209]: info: Connection to go-librespot Websocket established Aug 30 19:48:40 caramel-cajon go-librespot[2781]: time="2026-08-30T19:48:40+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:40 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:40 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:41 caramel-cajon volumio[1209]: info: Connection to go-librespot Websocket closed Aug 30 19:48:44 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 30 19:48:44 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:44 caramel-cajon volumio[1209]: info: Getting Spotify volume Aug 30 19:48:44 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:44 caramel-cajon volumio[1209]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 19:48:44 caramel-cajon go-librespot[2804]: go-librespot daemon starting... Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="app state loaded" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:44 caramel-cajon volumio[1209]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 19:48:44 caramel-cajon volumio[1209]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 30 19:48:44 caramel-cajon volumio[1209]: errno: -111, Aug 30 19:48:44 caramel-cajon volumio[1209]: code: 'ECONNREFUSED', Aug 30 19:48:44 caramel-cajon volumio[1209]: syscall: 'connect', Aug 30 19:48:44 caramel-cajon volumio[1209]: address: '127.0.0.1', Aug 30 19:48:44 caramel-cajon volumio[1209]: port: 9879, Aug 30 19:48:44 caramel-cajon volumio[1209]: response: undefined Aug 30 19:48:44 caramel-cajon volumio[1209]: } Aug 30 19:48:44 caramel-cajon volumio[1209]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=info msg="zeroconf server listening on port 36955" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="obtained new client token: AAHMiqD0nSyubElu3N6BQhvadC0hkXGW1T/mAoQjmtxHKTio25TguE8uQI+TSUjPZuSV/yJTif58Y2pIMbRdaJ/taz1x30sVi3cabcbZw5goJz4pDsHlbMv0dupTKr62tLR/R3zkndkK2LNJ3uh69Svmz6pigDdzBtB0165acquSiTlWSo+Su2ziAdT5FtC9tILAD72yHsB2N18RivEN1Dusc2rfyoUO6DISxmfpDREOD8HKIB9kVSrRbA==" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:44 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:44+09:00" level=debug msg="completed challenge" Aug 30 19:48:45 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:45+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:45 caramel-cajon go-librespot[2805]: time="2026-08-30T19:48:45+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:45 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:45 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:48 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Aug 30 19:48:48 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:48 caramel-cajon go-librespot[2839]: go-librespot daemon starting... Aug 30 19:48:48 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=debug msg="app state loaded" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=info msg="zeroconf server listening on port 45509" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:48 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:48+09:00" level=debug msg="obtained new client token: AAEs34nGw40sseQJee+BFcuL7zrffSx6mJySCXjrzEVVqD2MH3IC3QOjkdro3aDG7XqcPKz9H0OzVibrfZy2w21HQmSKcB5tIfOCu6J7ry+LWMIw52PZwQWo/4ADUncx1mXcwOK1LNDPSSpTK/ZsVu7J9MfrKvD1u4NwbgM2zrTH2L532uf0G/TpyNJLt7PRYJ88U+VYmRBzEehpgdYm9UHoxYFI0Bq+rS4ohm2Pdn07tZzW0OwGoPBcqQ==" Aug 30 19:48:49 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:49+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:49 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:49+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:49 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:49+09:00" level=debug msg="completed challenge" Aug 30 19:48:49 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:49+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:49 caramel-cajon go-librespot[2840]: time="2026-08-30T19:48:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:49 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:49 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 19:48:52 caramel-cajon systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 30 19:48:52 caramel-cajon systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:52 caramel-cajon systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 19:48:52 caramel-cajon go-librespot[2867]: go-librespot daemon starting... Aug 30 19:48:52 caramel-cajon sudo[2852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 19:47' Aug 30 19:48:52 caramel-cajon sudo[2852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 19:48:52 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:52+09:00" level=info msg="running go-librespot 0.7.1" Aug 30 19:48:52 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:52+09:00" level=debug msg="app state loaded" Aug 30 19:48:52 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:52+09:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=info msg="zeroconf server listening on port 38495" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="obtained new client token: AAEQszMyw+XBWhYVmGCo4wNg7Aozyh+P/El4AnZqtFdtCwOuLKXT1Qpr7YZJq3D5HqsFOt7M6gLefBikBDego6+JP+yfU9bu6skirqhJr7Vpyignfc8S83egffcK3FCuR3yPw4gpEA/wqieho/QcuqHC5ro6nTT5C4SrK9Ca8PlGguBgCH6qS7o9AzIZ2siG//8ma3eBUTfG+X2NrvYrw38/RA5Oz1c9hMa/KuG3M8sd5ck6dCdm+ZI=" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="completed keyexchange" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=debug msg="completed challenge" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=info msg="authenticated AP" username="31************************zi" Aug 30 19:48:53 caramel-cajon go-librespot[2868]: time="2026-08-30T19:48:53+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 19:48:53 caramel-cajon systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 19:48:53 caramel-cajon systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"