-- Logs begin at Thu 2025-07-17 16:04:48 CEST, end at Thu 2025-07-17 16:21:28 CEST. -- Jul 17 16:20:02 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:20:02 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:20:02 volumiostue volumio[947]: info: Listing playlists Jul 17 16:20:02 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:02 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. Jul 17 16:20:02 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:02 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:02 volumiostue go-librespot[4105]: go-librespot daemon starting... Jul 17 16:20:02 volumiostue go-librespot[4105]: time="2025-07-17T16:20:02+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:02 volumiostue go-librespot[4105]: time="2025-07-17T16:20:02+02:00" level=debug msg="app state loaded" Jul 17 16:20:02 volumiostue go-librespot[4105]: time="2025-07-17T16:20:02+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:02 volumiostue go-librespot[4105]: time="2025-07-17T16:20:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:03 volumiostue volumio-time-update[753]: volumio-time-update-util: Date not found in response Jul 17 16:20:03 volumiostue volumio-time-update[753]: volumio-time-update-util: Retrying in 5 seconds... Jul 17 16:20:04 volumiostue ntpd[984]: Soliciting pool server 162.159.200.123 Jul 17 16:20:06 volumiostue go-librespot[4105]: time="2025-07-17T16:20:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:06 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:06 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:08 volumiostue ntpd[984]: Soliciting pool server 86.52.112.177 Jul 17 16:20:08 volumiostue volumio-time-update[753]: volumio-time-update-util: Fetching time from Volumio... Jul 17 16:20:09 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:09 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85. Jul 17 16:20:09 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:09 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:09 volumiostue go-librespot[4133]: go-librespot daemon starting... Jul 17 16:20:09 volumiostue go-librespot[4133]: time="2025-07-17T16:20:09+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:09 volumiostue go-librespot[4133]: time="2025-07-17T16:20:09+02:00" level=debug msg="app state loaded" Jul 17 16:20:09 volumiostue go-librespot[4133]: time="2025-07-17T16:20:09+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:09 volumiostue go-librespot[4133]: time="2025-07-17T16:20:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:12 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:20:12 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:20:12 volumiostue go-librespot[4133]: time="2025-07-17T16:20:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:12 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:12 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:13 volumiostue ntpd[984]: Soliciting pool server 213.5.39.34 Jul 17 16:20:15 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:15 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Jul 17 16:20:15 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:15 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:15 volumiostue go-librespot[4157]: go-librespot daemon starting... Jul 17 16:20:15 volumiostue go-librespot[4157]: time="2025-07-17T16:20:15+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:15 volumiostue go-librespot[4157]: time="2025-07-17T16:20:15+02:00" level=debug msg="app state loaded" Jul 17 16:20:15 volumiostue go-librespot[4157]: time="2025-07-17T16:20:15+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:15 volumiostue go-librespot[4157]: time="2025-07-17T16:20:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:17 volumiostue ntpd[984]: Soliciting pool server 2606:4700:f1::123 Jul 17 16:20:18 volumiostue go-librespot[4157]: time="2025-07-17T16:20:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:18 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:18 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:21 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:21 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Jul 17 16:20:21 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:21 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:21 volumiostue go-librespot[4165]: go-librespot daemon starting... Jul 17 16:20:21 volumiostue go-librespot[4165]: time="2025-07-17T16:20:21+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:21 volumiostue go-librespot[4165]: time="2025-07-17T16:20:21+02:00" level=debug msg="app state loaded" Jul 17 16:20:21 volumiostue go-librespot[4165]: time="2025-07-17T16:20:21+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:21 volumiostue go-librespot[4165]: time="2025-07-17T16:20:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:22 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:20:22 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:20:22 volumiostue volumio[947]: info: Listing playlists Jul 17 16:20:24 volumiostue go-librespot[4165]: time="2025-07-17T16:20:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:24 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:24 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:27 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:27 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Jul 17 16:20:27 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:27 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:27 volumiostue go-librespot[4186]: go-librespot daemon starting... Jul 17 16:20:27 volumiostue go-librespot[4186]: time="2025-07-17T16:20:27+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:27 volumiostue go-librespot[4186]: time="2025-07-17T16:20:27+02:00" level=debug msg="app state loaded" Jul 17 16:20:27 volumiostue go-librespot[4186]: time="2025-07-17T16:20:27+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:27 volumiostue go-librespot[4186]: time="2025-07-17T16:20:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:31 volumiostue go-librespot[4186]: time="2025-07-17T16:20:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:31 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:31 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:32 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:20:32 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:20:34 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:34 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Jul 17 16:20:34 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:34 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:34 volumiostue go-librespot[4207]: go-librespot daemon starting... Jul 17 16:20:34 volumiostue go-librespot[4207]: time="2025-07-17T16:20:34+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:34 volumiostue go-librespot[4207]: time="2025-07-17T16:20:34+02:00" level=debug msg="app state loaded" Jul 17 16:20:34 volumiostue go-librespot[4207]: time="2025-07-17T16:20:34+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:34 volumiostue go-librespot[4207]: time="2025-07-17T16:20:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:36 volumiostue volumio-time-update[753]: volumio-time-update-util: Date not found in response Jul 17 16:20:36 volumiostue volumio-time-update[753]: volumio-time-update-util: Retrying in 5 seconds... Jul 17 16:20:37 volumiostue go-librespot[4207]: time="2025-07-17T16:20:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:37 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:37 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:40 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:40 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Jul 17 16:20:40 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:40 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:40 volumiostue go-librespot[4220]: go-librespot daemon starting... Jul 17 16:20:40 volumiostue go-librespot[4220]: time="2025-07-17T16:20:40+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:40 volumiostue go-librespot[4220]: time="2025-07-17T16:20:40+02:00" level=debug msg="app state loaded" Jul 17 16:20:40 volumiostue go-librespot[4220]: time="2025-07-17T16:20:40+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:40 volumiostue go-librespot[4220]: time="2025-07-17T16:20:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:41 volumiostue volumio-time-update[753]: volumio-time-update-util: Fetching time from Volumio... Jul 17 16:20:42 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:20:42 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:20:42 volumiostue volumio[947]: info: Listing playlists Jul 17 16:20:42 volumiostue volumio[947]: info: Listing playlists Jul 17 16:20:43 volumiostue go-librespot[4220]: time="2025-07-17T16:20:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:43 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:43 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:20:46 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:20:46 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Jul 17 16:20:46 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:20:46 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:20:46 volumiostue go-librespot[4245]: go-librespot daemon starting... Jul 17 16:20:46 volumiostue go-librespot[4245]: time="2025-07-17T16:20:46+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:20:46 volumiostue go-librespot[4245]: time="2025-07-17T16:20:46+02:00" level=debug msg="app state loaded" Jul 17 16:20:46 volumiostue go-librespot[4245]: time="2025-07-17T16:20:46+02:00" level=debug msg="stored credentials not found" Jul 17 16:20:46 volumiostue go-librespot[4245]: time="2025-07-17T16:20:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:20:52 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:20:52 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:20:59 volumiostue go-librespot[4245]: time="2025-07-17T16:20:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:20:59 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:20:59 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:02 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:21:02 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Jul 17 16:21:02 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:21:02 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:21:02 volumiostue go-librespot[4308]: go-librespot daemon starting... Jul 17 16:21:02 volumiostue go-librespot[4308]: time="2025-07-17T16:21:02+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:21:02 volumiostue go-librespot[4308]: time="2025-07-17T16:21:02+02:00" level=debug msg="app state loaded" Jul 17 16:21:02 volumiostue go-librespot[4308]: time="2025-07-17T16:21:02+02:00" level=debug msg="stored credentials not found" Jul 17 16:21:02 volumiostue go-librespot[4308]: time="2025-07-17T16:21:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:21:02 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:02 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:21:02 volumiostue volumio[947]: info: Listing playlists Jul 17 16:21:02 volumiostue volumio[947]: info: Listing playlists Jul 17 16:21:03 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 17 16:21:05 volumiostue go-librespot[4308]: time="2025-07-17T16:21:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:21:05 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:21:05 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:08 volumiostue ntpd[984]: Soliciting pool server 46.32.144.141 Jul 17 16:21:08 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:21:08 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Jul 17 16:21:08 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:21:08 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:21:08 volumiostue go-librespot[4329]: go-librespot daemon starting... Jul 17 16:21:08 volumiostue go-librespot[4329]: time="2025-07-17T16:21:08+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:21:08 volumiostue go-librespot[4329]: time="2025-07-17T16:21:08+02:00" level=debug msg="app state loaded" Jul 17 16:21:08 volumiostue go-librespot[4329]: time="2025-07-17T16:21:08+02:00" level=debug msg="stored credentials not found" Jul 17 16:21:08 volumiostue go-librespot[4329]: time="2025-07-17T16:21:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:21:09 volumiostue volumio-time-update[753]: volumio-time-update-util: Date not found in response Jul 17 16:21:09 volumiostue volumio-time-update[753]: volumio-time-update-util: Retrying in 5 seconds... Jul 17 16:21:11 volumiostue go-librespot[4329]: time="2025-07-17T16:21:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:21:11 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:21:11 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:12 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:12 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:21:14 volumiostue volumio[947]: info: CorePlayQueue::getTrack 2 Jul 17 16:21:14 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:14 volumiostue volumio[947]: info: Prefetching next song Jul 17 16:21:14 volumiostue volumio-time-update[753]: volumio-time-update-util: Fetching time from Volumio... Jul 17 16:21:14 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:21:14 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Jul 17 16:21:14 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:21:14 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:21:14 volumiostue go-librespot[4355]: go-librespot daemon starting... Jul 17 16:21:14 volumiostue go-librespot[4355]: time="2025-07-17T16:21:14+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:21:14 volumiostue go-librespot[4355]: time="2025-07-17T16:21:14+02:00" level=debug msg="app state loaded" Jul 17 16:21:14 volumiostue go-librespot[4355]: time="2025-07-17T16:21:14+02:00" level=debug msg="stored credentials not found" Jul 17 16:21:14 volumiostue go-librespot[4355]: time="2025-07-17T16:21:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:21:15 volumiostue ntpd[984]: Soliciting pool server 5.186.224.242 Jul 17 16:21:17 volumiostue go-librespot[4355]: time="2025-07-17T16:21:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:21:17 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:21:17 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:18 volumiostue volumio[947]: info: CoreStateMachine::startPlaybackTimer Jul 17 16:21:18 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:18 volumiostue volumio[947]: info: CoreStateMachine::pushState Jul 17 16:21:18 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:18 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 17 16:21:18 volumiostue volumio[947]: info: CoreCommandRouter::volumioPushState Jul 17 16:21:19 volumiostue ntpd[984]: Soliciting pool server 185.181.223.169 Jul 17 16:21:20 volumiostue volumio[947]: info: CoreCommandRouter::volumioPlay Jul 17 16:21:20 volumiostue volumio[947]: info: CoreStateMachine::play index undefined Jul 17 16:21:20 volumiostue volumio[947]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 17 16:21:20 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:20 volumiostue volumio[947]: info: CoreStateMachine::startPlaybackTimer Jul 17 16:21:20 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:20 volumiostue volumio[947]: info: [jellyfin-play] clearAddPlayTrack: jellyfin/player@309b9f63de4d47b4a09055308b992532/song@songId=16b9a2b6a30c573db341447c768da757 Jul 17 16:21:20 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:21:20 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Jul 17 16:21:20 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:21:20 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:21:20 volumiostue go-librespot[4366]: go-librespot daemon starting... Jul 17 16:21:20 volumiostue go-librespot[4366]: time="2025-07-17T16:21:20+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:21:20 volumiostue go-librespot[4366]: time="2025-07-17T16:21:20+02:00" level=debug msg="app state loaded" Jul 17 16:21:20 volumiostue go-librespot[4366]: time="2025-07-17T16:21:20+02:00" level=debug msg="stored credentials not found" Jul 17 16:21:20 volumiostue go-librespot[4366]: time="2025-07-17T16:21:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:21:21 volumiostue go-librespot[4366]: time="2025-07-17T16:21:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 35.186.224.24:443: connect: no route to host" Jul 17 16:21:21 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:21:21 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:22 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:22 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:22 volumiostue volumio[947]: info: Listing playlists Jul 17 16:21:22 volumiostue volumio[947]: info: Listing playlists Jul 17 16:21:23 volumiostue ntpd[984]: Soliciting pool server 2a00:1f98:1001:6e31:2e74:6175:722e:646b Jul 17 16:21:24 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:21:24 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Jul 17 16:21:24 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:21:24 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:21:24 volumiostue go-librespot[4387]: go-librespot daemon starting... Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="app state loaded" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="stored credentials not found" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=info msg="zeroconf server listening on port 44365" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="obtained new client token: AAAyZ4ubrjp5+eGO69vnLyHEyk6vgI8unhD0yFaFPwmPAiMyd3kDKfedrFv4q+Fs035Kh9bdLTVp4VFlGFSOoLq7Bii5GLBdUVcJdG17Vg2aGzBwu6hY+lanPsXxg1hl79Xz1ltJLX35n9b2oFJLu+BI2T0tiLL16sk9J5uArBMQpLdDz+j+Fhz+AYZizYuYjGxbGXL26D3V14m7nNQHCIUhm5krx9K1X9RLjgZI+IdvO2UHP/5rG/E=" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="completed keyexchange" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=debug msg="completed challenge" Jul 17 16:21:24 volumiostue go-librespot[4387]: time="2025-07-17T16:21:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 17 16:21:24 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:21:24 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jul 17 16:21:25 volumiostue volumio[947]: info: [jellyfin-poller] Polled http://local.jellyfin:8096: offline (lost) Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Jul 17 16:21:25 volumiostue sudo[4396]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 17 16:21:25 volumiostue sudo[4396]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 17 16:21:25 volumiostue sudo[4396]: pam_unix(sudo:session): session closed for user root Jul 17 16:21:25 volumiostue sudo[4398]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 17 16:21:25 volumiostue sudo[4398]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 17 16:21:25 volumiostue sudo[4398]: pam_unix(sudo:session): session closed for user root Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Jul 17 16:21:25 volumiostue volumio[947]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to 192.168.1.156 from 192.168.1.179 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:140.0) Gecko/20100101 Firefox/140.0 Engine version: 3 Transport: polling Total Clients: 21 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Jul 17 16:21:25 volumiostue volumio[947]: error: [jellyfin-play] Prefetch failed: Error: connect ECONNREFUSED 192.168.1.202:8096 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 29 Jul 17 16:21:25 volumiostue volumio[947]: error: [jellyfin-play] Prefetch failed: Error: connect ECONNREFUSED 192.168.1.202:8096 Jul 17 16:21:25 volumiostue volumio[947]: (node:947) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 192.168.1.202:8096 Jul 17 16:21:25 volumiostue volumio[947]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 17 16:21:25 volumiostue volumio[947]: (node:947) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 16) Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 17 16:21:25 volumiostue volumio[947]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 30 Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetVisibleSources Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:25 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 17 16:21:25 volumiostue volumio[947]: info: Received Get System Info Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 17 16:21:25 volumiostue volumio[947]: info: Discovery: Getting this device information Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:25 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:25 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:25 volumiostue volumio[947]: info: Listing playlists Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 17 16:21:25 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:25 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:26 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:26 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin bluetooth to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin multiroom to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin metavolumio to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin cd_controller to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin qobuzconnect to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin smart_inputs to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: Adding plugin tidalconnect to MyMusic Plugins Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jul 17 16:21:26 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 16:21:26 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 16:21:26 volumiostue volumio[947]: info: Starting MyVolumio Remote Streaming Endpoints Jul 17 16:21:26 volumiostue volumio[947]: info: MyVolumio login type: Token Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jul 17 16:21:26 volumiostue volumio[947]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jul 17 16:21:27 volumiostue volumio[947]: info: Starting Streaming Service Transparent Proxy Jul 17 16:21:27 volumiostue volumio[947]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jul 17 16:21:27 volumiostue volumio[947]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jul 17 16:21:27 volumiostue volumio[947]: info: Streaming services startup Jul 17 16:21:27 volumiostue volumio[947]: info: Starting Streaming Daemon Jul 17 16:21:27 volumiostue sudo[4408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 17 16:21:27 volumiostue sudo[4408]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 17 16:21:27 volumiostue volumio[947]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jul 17 16:21:27 volumiostue sudo[4408]: pam_unix(sudo:session): session closed for user root Jul 17 16:21:27 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jul 17 16:21:27 volumiostue volumio[947]: error: Cannot start Volumio Streaming Daemon Jul 17 16:21:27 volumiostue volumio[947]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 17 16:21:27 volumiostue volumio[947]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 17 16:21:27 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 17 16:21:27 volumiostue volumio[947]: info: Received Get System Info Jul 17 16:21:27 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 17 16:21:27 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 17 16:21:27 volumiostue volumio[947]: info: Discovery: Getting this device information Jul 17 16:21:27 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:27 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:27 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 17 16:21:27 volumiostue volumio[947]: STREAMING PROXY: Starting server on port 3245 Jul 17 16:21:27 volumiostue volumio[947]: Node JS runtime: 14 Jul 17 16:21:27 volumiostue systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 17 16:21:27 volumiostue systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Jul 17 16:21:27 volumiostue systemd[1]: Stopped go-librespot Daemon. Jul 17 16:21:27 volumiostue systemd[1]: Started go-librespot Daemon. Jul 17 16:21:27 volumiostue go-librespot[4415]: go-librespot daemon starting... Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=info msg="running go-librespot 0.2.0" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="app state loaded" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="stored credentials not found" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 16:21:27 volumiostue volumio[947]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=info msg="zeroconf server listening on port 38995" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="obtained new client token: AADH1SimVaHx+IPGoUe/EjLbJMdlreBEXkfcr+dmYVRl4HaUH5Qt7iokxBsWE2NOyx9+LZA2ekmh8wi8rxyXT/nEXDEANzTp1lr70NjcDrGr8n1bPzoXY3h8qTBC5S7qfKGKBZ2jdSGHT4PbpgvMa41yBXz9AUEwANvGijX/6BMr4NTFySuUmLGjn9Wi+IrIdLIxk9XEMrSC4UDVjoNWwb2eiJ3Fl8K7nd2Cfs9xudWw8kKwk/VzdFu1tg==" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="completed keyexchange" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=debug msg="completed challenge" Jul 17 16:21:27 volumiostue go-librespot[4415]: time="2025-07-17T16:21:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jul 17 16:21:27 volumiostue systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 16:21:27 volumiostue systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 16:21:28 volumiostue volumio[947]: info: MyVolumio token set successfully Jul 17 16:21:28 volumiostue volumio[947]: info: MYVOLUMIO: Adding device Jul 17 16:21:28 volumiostue volumio[947]: info: MYVOLUMIO: Evaluating Server Jul 17 16:21:28 volumiostue volumio[947]: info: Initializing connection to go-librespot Websocket Jul 17 16:21:28 volumiostue volumio[947]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 17 16:21:28 volumiostue volumio-time-update[753]: volumio-time-update-util: Setting system time to: 2025-07-17 16:21:28 Jul 17 16:21:28 volumiostue sudo[4427]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-07-17 16:21:28 Jul 17 16:21:28 volumiostue sudo[4427]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 17 16:21:28 volumiostue dbus-daemon[717]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.16' (uid=0 pid=4429 comm="timedatectl set-time 2025-07-17 16:21:28 ") Jul 17 16:21:28 volumiostue systemd[1]: Starting Time & Date Service... Jul 17 16:21:28 volumiostue volumio[947]: info: MyVolumio status changed Jul 17 16:21:28 volumiostue volumio[947]: info: Streaming services startup Jul 17 16:21:28 volumiostue volumio[947]: info: Starting Streaming Daemon Jul 17 16:21:28 volumiostue dbus-daemon[717]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 17 16:21:28 volumiostue systemd[1]: Started Time & Date Service. Jul 17 16:21:28 volumiostue volumio[947]: info: Removing browser output: myVolumio user plan is not superstar Jul 17 16:21:28 volumiostue volumio[947]: info: Removing audio output: Jul 17 16:21:28 volumiostue volumio[947]: info: Stoppping Tunnel 1 Jul 17 16:21:28 volumiostue systemd-timedated[4433]: Changed local time to Thu Jul 17 16:21:28 2025 Jul 17 16:21:28 volumiostue sudo[4444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 17 16:21:28 volumiostue sudo[4444]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 17 16:21:28 volumiostue sudo[4427]: pam_unix(sudo:session): session closed for user root Jul 17 16:21:28 volumiostue volumio-time-update[753]: volumio-time-update-util: System time updated successfully. Jul 17 16:21:28 volumiostue systemd[1]: Started Volumio Time Update Utility. Jul 17 16:21:28 volumiostue sudo[4448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jul 17 16:21:28 volumiostue systemd[1]: Reached target Multi-User System. Jul 17 16:21:28 volumiostue sudo[4448]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 17 16:21:28 volumiostue systemd[1]: Reached target Graphical Interface. Jul 17 16:21:28 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 17 16:21:28 volumiostue volumio[947]: info: Received Get System Info Jul 17 16:21:28 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 17 16:21:28 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 17 16:21:28 volumiostue volumio[947]: info: Discovery: Getting this device information Jul 17 16:21:28 volumiostue volumio[947]: info: CoreCommandRouter::volumioGetState Jul 17 16:21:28 volumiostue volumio[947]: info: CorePlayQueue::getTrack 3 Jul 17 16:21:28 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 17 16:21:28 volumiostue volumio[947]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jul 17 16:21:28 volumiostue volumio[947]: info: MyVolumio login type: Token Jul 17 16:21:28 volumiostue systemd[1]: Starting Update UTMP about System Runlevel Changes... Jul 17 16:21:28 volumiostue sudo[4444]: pam_unix(sudo:session): session closed for user root Jul 17 16:21:28 volumiostue volumio[947]: error: Cannot start Volumio Streaming Daemon Jul 17 16:21:28 volumiostue volumio[947]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 17 16:21:28 volumiostue volumio[947]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 17 16:21:28 volumiostue systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jul 17 16:21:28 volumiostue systemd[1]: Started Update UTMP about System Runlevel Changes. Jul 17 16:21:28 volumiostue systemd[1]: Startup finished in 10.458s (kernel) + 16min 39.856s (userspace) = 16min 50.315s. Jul 17 16:21:28 volumiostue sudo[4448]: pam_unix(sudo:session): session closed for user root Jul 17 16:21:28 volumiostue volumio[947]: info: Remote SSH Stopped Jul 17 16:21:28 volumiostue volumio[947]: error: Failed to ping endpoint us1.myvolumio.org : unknown error Jul 17 16:21:28 volumiostue volumio[947]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 17 16:21:28 volumiostue volumio[947]: Error: Unable to resolve or reject the same promise twice Jul 17 16:21:28 volumiostue volumio[947]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jul 17 16:21:28 volumiostue volumio[947]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Jul 17 16:21:28 volumiostue volumio[947]: at Socket.emit (events.js:327:22) Jul 17 16:21:28 volumiostue volumio[947]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 17 16:21:28 volumiostue volumio[947]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 17 16:21:28 volumiostue volumio[947]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 17 16:21:28 volumiostue sudo[4461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-17 16:20 Jul 17 16:21:28 volumiostue sudo[4461]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:07:25 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3b9115b1943141a9d7186aa434f8f3c2"