-- Logs begin at Thu 2019-02-14 13:11:58 +03, end at Wed 2026-04-15 11:54:51 +03. -- Apr 15 11:53:01 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:01 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:02 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 11:53:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Apr 15 11:53:02 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:02 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:02 volumio go-librespot[2238]: go-librespot daemon starting... Apr 15 11:53:02 volumio go-librespot[2238]: time="2026-04-15T11:53:02+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:02 volumio go-librespot[2238]: time="2026-04-15T11:53:02+03:00" level=debug msg="app state loaded" Apr 15 11:53:02 volumio go-librespot[2238]: time="2026-04-15T11:53:02+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=info msg="zeroconf server listening on port 33197" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="obtained new client token: AACo/5O1CQ1PHBu4RVl0Sxh7do5CW3KyeOdZryWY+eIE0laGAEpWuf9nTr5lQSTF4wJ1EUQE8dDuo9BQOTcF+p8wHBEoN34zjwKsqoFkEaXu0cICU0ne2i9+EwRWmCkSaRDDUvNPQzSRknKHajuFUX/JjhRv/f2feG/GH0FzOVkj6ntPcGrcfX6qB0r2iHqer1atd1q+O2mTF5HML/Eno8wNi1hIlvxnw0uGDlpe9MT7OTF9bhoUQz00" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=debug msg="completed challenge" Apr 15 11:53:03 volumio go-librespot[2238]: time="2026-04-15T11:53:03+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:04 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:04 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Apr 15 11:53:06 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:06 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:06 volumio go-librespot[2252]: go-librespot daemon starting... Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="app state loaded" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=info msg="zeroconf server listening on port 41189" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="obtained new client token: AAAiNoF0x7tKlFi1xePaHRgcP0MImVIHbWXdQ/p3p1ptjBA/iNlrbjovyKg+PTfxMaijLMM/QbR7B618J23m4C0Ar8a36egvMji8nJP0QeunHwsLbxd/c/sQ9j0UmgnwE4WjyXzq5CNt6e59rDx4BAhgFgFs/TehpSeah5zZgVBk/2yDnVbm4LMO85rRuel+dZ/sJC/fSIPcyPg+7r6dq4LLH+Ot2iXP27xq3MhwpGhRoDIyN2gFquM7ij4=" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=debug msg="completed challenge" Apr 15 11:53:06 volumio go-librespot[2252]: time="2026-04-15T11:53:06+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:07 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:07 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:09 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 15 11:53:09 volumio volumio[801]: info: CURURI: music-library/NAS/MEDIA/DJs Apr 15 11:53:09 volumio volumio[801]: info: Preload queue cleared Apr 15 11:53:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Apr 15 11:53:09 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:09 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:09 volumio go-librespot[2269]: go-librespot daemon starting... Apr 15 11:53:09 volumio go-librespot[2269]: time="2026-04-15T11:53:09+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:09 volumio go-librespot[2269]: time="2026-04-15T11:53:09+03:00" level=debug msg="app state loaded" Apr 15 11:53:09 volumio go-librespot[2269]: time="2026-04-15T11:53:09+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=info msg="zeroconf server listening on port 41789" Apr 15 11:53:10 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="new websocket client" Apr 15 11:53:10 volumio volumio[801]: info: Connection to go-librespot Websocket established Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="obtained new client token: AACIr6D41FLFzirLxQ2BPqINqTv4bOyHJi1RMSBLrrIRoJVLvodEoSr2hPk+XEYWeDqVwjlSQGg0NETcW5tBjdwiU4Z3ouuA1PGSf8Q5dLTzamAvMztsbyO7gIntGI2YlwyrVHCERxYJ4YLrYIfxtHmx2+n50Ji8f+0yT+6d6hCzaGvjPkgfG/ZTKvmwRDiFI+lOIzFPXGKI4XRA6EhZb7N72oSg+6ekS4PND8h5lGOyVLkgK6/EoVDS" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=debug msg="completed challenge" Apr 15 11:53:10 volumio go-librespot[2269]: time="2026-04-15T11:53:10+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:10 volumio volumio[801]: info: Connection to go-librespot Websocket closed Apr 15 11:53:11 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 15 11:53:11 volumio volumio[801]: info: CURURI: music-library/NAS/MEDIA/DJs/2025 Apr 15 11:53:11 volumio volumio[801]: info: Preload queue cleared Apr 15 11:53:13 volumio volumio[801]: info: Getting Spotify volume Apr 15 11:53:13 volumio volumio[801]: (node:801) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:13 volumio volumio[801]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 11:53:13 volumio volumio[801]: (node:801) 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: 5) Apr 15 11:53:13 volumio volumio[801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 15 11:53:13 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:13 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Apr 15 11:53:13 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:13 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:13 volumio go-librespot[2297]: go-librespot daemon starting... Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="app state loaded" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:13 volumio volumio[801]: info: Preload queue cleared Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::ClearQueue Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::stop Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::stPlaybackTimer Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::serviceStop Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::serviceStop Apr 15 11:53:13 volumio volumio[801]: info: [1776243193537] ControllerWebradio::stop Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::clearPlayQueue Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::addQueueItems Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::addQueueItems Apr 15 11:53:13 volumio volumio[801]: info: Preload queue cleared Apr 15 11:53:13 volumio volumio[801]: info: Adding Item to queue: music-library/NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3 Apr 15 11:53:13 volumio volumio[801]: info: Using cached record of: music-library/NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::play index 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::addQueueItems Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::addQueueItems Apr 15 11:53:13 volumio volumio[801]: info: Preload queue cleared Apr 15 11:53:13 volumio volumio[801]: info: Adding Item to queue: music-library/NAS/MEDIA/DJs/2025/Merry Christmas Baby - Swing Republic (Audio) #electroswing #christmas.mp3 Apr 15 11:53:13 volumio volumio[801]: info: Using cached record of: music-library/NAS/MEDIA/DJs/2025/Merry Christmas Baby - Swing Republic (Audio) #electroswing #christmas.mp3 Apr 15 11:53:13 volumio volumio[801]: info: Adding Item to queue: music-library/NAS/MEDIA/DJs/2025/Take_Five_-_XL_Smooth_Jazz_Mix.mp3 Apr 15 11:53:13 volumio volumio[801]: info: Using cached record of: music-library/NAS/MEDIA/DJs/2025/Take_Five_-_XL_Smooth_Jazz_Mix.mp3 Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::stop Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::startPlaybackTimer Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::clearAddPlayTracks NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3 Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Handling event: musicStop Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand stop took 43 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand stop took 7 milliseconds Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clear Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:13 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:13 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand status took 5 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand clear took 4 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand add "NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3" Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:13 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 11:53:13 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio volumio[801]: info: No code Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 11:53:13 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio volumio[801]: info: No code Apr 15 11:53:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:13 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=info msg="zeroconf server listening on port 38197" Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 53ms Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 53ms Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:13 volumio volumio[801]: error: updateQueue error: null Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 59ms Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand playlistinfo took 57 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand add "NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3" took 58 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 7ms Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand play Apr 15 11:53:13 volumio volumio[801]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 66ms Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:13 volumio volumio[801]: info: Apr 15 11:53:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 19ms Apr 15 11:53:13 volumio volumio[801]: info: sendMpdCommand play took 18 milliseconds Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 17ms Apr 15 11:53:13 volumio volumio[801]: info: ------------------------------ 16ms Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="obtained new client token: AABIkOk/eJzlrIFkXCXhSYVFrsLtYe9xYFEjHzWqFgb1SE9BGJsYgcdZf6hXRLNF/TBpQAMxPxOxTE+KY6la+iQEczHkAXQUNwRWy2MOIwE8qlOa2a6A4q/Lfus7r+bWicYziMC/kNoc4ZG6w+s6JXcraM+nM12ZUUqnM0XjzfG73fdmHwGUbtnTE7c0BIQGGqZyM4bQOujhALwNLDCEg5gfojkeip33GLWBrPsn3gIaeKKJSA4sAMDq+dw=" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=debug msg="completed challenge" Apr 15 11:53:13 volumio go-librespot[2297]: time="2026-04-15T11:53:13+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Apr 15 11:53:17 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:17 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:17 volumio go-librespot[2310]: go-librespot daemon starting... Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="app state loaded" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=info msg="zeroconf server listening on port 33659" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="obtained new client token: AABLxF9rSufjEGMW7z6bgnyUh/RjkQw9te8/5odwlEx6u/MKXYyH6JGoRDWNpNvt9qTbYpVZFa0GcrvWl/w2sH/dNsaIuoCQ5M9+1K1xh+mzZH0mdFmwztsJ8trvQ74Ag54zS2HRBseL7vzKuD4+4ejU203FCgjt0nkX3/LtnVwB1YmE3WOOPXAYbQ8sWn5gEXzLEl5DcVgcmB1pUjedA/DPky3222VUWmn2UXsiNC9ByRoXGroaxi9+ZpU=" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=debug msg="completed challenge" Apr 15 11:53:17 volumio go-librespot[2310]: time="2026-04-15T11:53:17+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Apr 15 11:53:20 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:20 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:20 volumio go-librespot[2318]: go-librespot daemon starting... Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=debug msg="app state loaded" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=info msg="zeroconf server listening on port 34609" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=debug msg="obtained new client token: AAAsrT83XQZKm6Hik6YvnlEkDu8i+kTX+s0bVtGwipL54SGWiD5ZJ0bFRLhwImzBELrO7ej7Z9k4epNnS5Qz8xVByagOgQPozaQvqmYBUIhYB203N9+cZtYxvvCTk7C5u//NfvGKGhfkmeiNAyEPbJMDxNG617xRUC2277tBpuelCybMTnJPE2Fi1NM29GEJApFnyaAf+9FVnUE9bs6RrGnue5X58Tpq227JezqncpxS1hrYHIe7g6ZFuYU=" Apr 15 11:53:20 volumio go-librespot[2318]: time="2026-04-15T11:53:20+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:21 volumio go-librespot[2318]: time="2026-04-15T11:53:21+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:21 volumio go-librespot[2318]: time="2026-04-15T11:53:21+03:00" level=debug msg="completed challenge" Apr 15 11:53:21 volumio go-librespot[2318]: time="2026-04-15T11:53:21+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:22 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::startPlaybackTimer Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::clearAddPlayTracks NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3 Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: Upnp client error: Error: This socket has been ended by the other party Apr 15 11:53:22 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand stop took 8 milliseconds Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clear Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:22 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 8 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 8 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 8 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand clear took 3 milliseconds Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand add "NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3" Apr 15 11:53:22 volumio volumio[801]: Upnp client error: Error: This socket has been ended by the other party Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: Upnp client error: Error: This socket has been ended by the other party Apr 15 11:53:22 volumio volumio[801]: error: updateQueue error: null Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:22 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 9 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 9ms Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand add "NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3" took 6 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 4 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand play Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 11:53:22 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: No code Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 15 11:53:22 volumio volumio[801]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 15 11:53:22 volumio volumio[801]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 11:53:22 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: No code Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 11:53:22 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: No code Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 85ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 92ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 91ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 90ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 80ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 79ms Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:22 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:53:22 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 81ms Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand play took 77 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 28ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 27ms Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 25 milliseconds Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: Apr 15 11:53:22 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand status took 1 milliseconds Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3","artist":null,"album":null,"uri":"NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3","trackType":"mp3"} Apr 15 11:53:22 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 33ms Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 15 11:53:22 volumio volumio[801]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:22 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3","artist":null,"album":null,"uri":"NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3","trackType":"mp3"} Apr 15 11:53:22 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:53:22 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3","artist":null,"album":null,"uri":"NAS/MEDIA/DJs/2025/Jakatta_-_American_Dream_Andre_Crom_Chi_Thanh_Remix.mp3","trackType":"mp3"} Apr 15 11:53:22 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:53:22 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:53:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:22 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 36ms Apr 15 11:53:22 volumio volumio[801]: info: ------------------------------ 35ms Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Handling event: musicPlay Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:53:22 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:53:23 volumio volumio[801]: verbose: New Socket.io Connection to 192.168.15.10 from 192.168.15.70 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 15 11:53:23 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 15 11:53:23 volumio volumio[801]: info: Received Get System Info Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 11:53:23 volumio volumio[801]: info: Discovery: Getting this device information Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 15 11:53:23 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 15 11:53:23 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:53:23 volumio volumio[801]: info: Listing playlists Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::volumioGetQueue Apr 15 11:53:23 volumio volumio[801]: info: CoreStateMachine::getQueue Apr 15 11:53:23 volumio volumio[801]: info: CorePlayQueue::getQueue Apr 15 11:53:23 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 15 11:53:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Apr 15 11:53:24 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:24 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:24 volumio go-librespot[2348]: go-librespot daemon starting... Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=debug msg="app state loaded" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=info msg="zeroconf server listening on port 40875" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=debug msg="obtained new client token: AABmVabyg5Te/2UWAbhUOhNTRP3o55WFAjfaBkfO1x6omZcdYMWOxsrO7T8cwS13LGcOE2KcjfcT5YXPCeH1R//Aoh+3DTpDTzYs7mfTRHXABwwkEHBQnR1ZNmRj+ThxfmV+f+MBY0hiKJLOPFvAwpaB0bbHVcYjRlljE0TdHXo5Vi9gwGi4Ee8ATaEcrWA9x5hqZOxeLTnPmr0H8rxApc3t5qN676JTYHAXYX0BWEjEb4jOCx76u3wcurI=" Apr 15 11:53:24 volumio go-librespot[2348]: time="2026-04-15T11:53:24+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:25 volumio go-librespot[2348]: time="2026-04-15T11:53:25+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:25 volumio go-librespot[2348]: time="2026-04-15T11:53:25+03:00" level=debug msg="completed challenge" Apr 15 11:53:25 volumio go-librespot[2348]: time="2026-04-15T11:53:25+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:25 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:25 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Apr 15 11:53:28 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:28 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:28 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:28 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:28 volumio go-librespot[2402]: go-librespot daemon starting... Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=debug msg="app state loaded" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=info msg="zeroconf server listening on port 38587" Apr 15 11:53:28 volumio go-librespot[2402]: time="2026-04-15T11:53:28+03:00" level=debug msg="obtained new client token: AADXwck5CNIABRF68s0jZLWN1OyV7Dx8WHj6vA/wwUXOBoY1riNNC6zmjmrcdE5qNMDdp2RW5R+mPqTvuFGqa7WN4V8mYWQpWc2yIhDNChiUipMpZVOqhB8djOH/+lW74gonm9J1ddYOg1exet+RtgP0bqj+9xf5lbrrWJUNzoLPVLdTsF22wYkND1P+cfptwBjagktjs4XwtPvHefUmmPwEemyXypLxRgzJDGs/O6/0hTyXGpAS4MHP2m4=" Apr 15 11:53:29 volumio go-librespot[2402]: time="2026-04-15T11:53:29+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:29 volumio go-librespot[2402]: time="2026-04-15T11:53:29+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:29 volumio go-librespot[2402]: time="2026-04-15T11:53:29+03:00" level=debug msg="completed challenge" Apr 15 11:53:29 volumio go-librespot[2402]: time="2026-04-15T11:53:29+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:31 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:31 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Apr 15 11:53:32 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:32 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:32 volumio go-librespot[2432]: go-librespot daemon starting... Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="app state loaded" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=info msg="zeroconf server listening on port 40011" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="obtained new client token: AADBG6bSV124nCwM66b3ow3u7eltjrj/CXP0pAAl4wGX7bzbkZj4KbIiM19Qrdb+r5k676j+zrKgM68xhInmtjM+j1+gQ8x0D2bIU8o+4MsBv9qFeDzXInYmw1q+aRxGFSxuucL5Y2oTI7sCiLpPetXh4iGXhNkFwoKTJrUUsTs6riVBOOqn/N3RFq6t+Hu2D8YAICQfW10MlEAGgJ1xPPUPJq7xXKRGJQQ/ozDOODUAhjruoUFA1l50yY4=" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=debug msg="completed challenge" Apr 15 11:53:32 volumio go-librespot[2432]: time="2026-04-15T11:53:32+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:34 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:34 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Apr 15 11:53:35 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:35 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:35 volumio go-librespot[2447]: go-librespot daemon starting... Apr 15 11:53:35 volumio go-librespot[2447]: time="2026-04-15T11:53:35+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:35 volumio go-librespot[2447]: time="2026-04-15T11:53:35+03:00" level=debug msg="app state loaded" Apr 15 11:53:35 volumio go-librespot[2447]: time="2026-04-15T11:53:35+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=info msg="zeroconf server listening on port 45711" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="obtained new client token: AAAOx6ySpH+64mCSg35MQAKV9CBbVoADYuy7d30gXp7k34zX+B+/FVeV8feCSbjpscvFIBsMmPXuQtKtGK93SaEprHOdQnIMCqqce2OhOtj1EkWsg+GSXna5aoeDC4Kl/snawFBJM4Xv2tytMgAyDwlj0f17xZitqjM+D9upVXoC8znG24kBX/4ZLtWmBWQiOUritr8vrXnI2UDoz0g4OqqVpRd5od4IKBR+lO8fSPjFnHNAAVi89eNE" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=debug msg="completed challenge" Apr 15 11:53:36 volumio go-librespot[2447]: time="2026-04-15T11:53:36+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:37 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:37 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Apr 15 11:53:39 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:39 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:39 volumio go-librespot[2464]: go-librespot daemon starting... Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="app state loaded" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=info msg="zeroconf server listening on port 44583" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="obtained new client token: AACuyqbIbd+uy30ZaT4rr4wPM29TOVHw3AEoVRWH2MovNyVp0JhyIzKgl3LiGTJwU45VEOlkHDhsGqhXI1mfHcPV7kr4sBShEjK8SxJbCCRTkQKhvxzSuYln6YXmIlNNQuXQpgJXpz1zUzZuxLqkwr0adCVTAsGYRAxtNmxpIbmA4T5WYDxk6cqX01lkV1BJcUSWjDy28NPHZYR46JeDBwWKASXEvjO1mQg+ImwqPJzI5QX5eKbQ1qyj8ms=" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=debug msg="completed challenge" Apr 15 11:53:39 volumio go-librespot[2464]: time="2026-04-15T11:53:39+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:40 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:40 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Apr 15 11:53:43 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:43 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:43 volumio go-librespot[2494]: go-librespot daemon starting... Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="app state loaded" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=info msg="zeroconf server listening on port 35173" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="obtained new client token: AAByLD3lIDnD8PBstGdV8LANMoKk79VPfpIvb8ykIYkdG2MOIPMdE6kIisjUNG2g+YVusoX40NbsvMYhxIE95+OoEaHvki8uNZikPgYsscDEd+Xmk8jVtI46MG+IALokjBknVT6dMN71JcRIZ9pxYqtuH040o7RAVwBfkxQIrPy3G4go7YBexjaGAk5vKC38UjGpK+JVMwbpYbR9CHS4I5SyE0IMG5Ogpk4/fjHpR+Ys8zZlpxJPAO2puf8=" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=debug msg="completed challenge" Apr 15 11:53:43 volumio go-librespot[2494]: time="2026-04-15T11:53:43+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:43 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:43 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:46 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:46 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Apr 15 11:53:46 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:46 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:46 volumio go-librespot[2508]: go-librespot daemon starting... Apr 15 11:53:46 volumio go-librespot[2508]: time="2026-04-15T11:53:46+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:46 volumio go-librespot[2508]: time="2026-04-15T11:53:46+03:00" level=debug msg="app state loaded" Apr 15 11:53:46 volumio go-librespot[2508]: time="2026-04-15T11:53:46+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=info msg="zeroconf server listening on port 38221" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="obtained new client token: AABjzDk+9Xd5xkDkCy9avNQ5KvBFZfX1ioAojLqajCGMaJSMf+RDtafQTE6ortyDok1K+Pycub32aEwJWOpgh27jKLw4AhAAE8He1WHWHwbHNRX+Tem/urz1LuB9zO0mCPw7EMvnq5Y9NHicbMtYpXgXjB3yfXdc8TSchmESAX0DKCaMbx8eCi/kD+Cvkok2n+nHfek/3hDIefjdYJQ+chBjrPg+NqPOr+SbyMGQ61RV7AR1MRfJN2x2" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=debug msg="completed challenge" Apr 15 11:53:47 volumio go-librespot[2508]: time="2026-04-15T11:53:47+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:49 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:49 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Apr 15 11:53:50 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:50 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:50 volumio go-librespot[2524]: go-librespot daemon starting... Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="app state loaded" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=info msg="zeroconf server listening on port 40935" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="obtained new client token: AAC0C+Lxbp/B1qtGlN3AiiEzJ0E85iKpX8cdjhY1y5CHC9Z/qvTwcalsaYWdD9/0YJoCyx3jDHih0Cdar4ZlQ/6EVcoMe8GAmKn+sKbAet1z7D5JpruMFUEBJYZUi+yJfZPItqkQNyJmlL9q9zXr/Lq/MCL1G05aCEIqrcwNqTd79FtTO3SJ+8hDSZVZMbln4Idoi66G6nWprlyvtiUKqOie9K6RXWRA7shc30kqWxwrm+EHRpllL3HZfVs=" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=debug msg="completed challenge" Apr 15 11:53:50 volumio go-librespot[2524]: time="2026-04-15T11:53:50+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:52 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:52 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Apr 15 11:53:53 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:53 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:53 volumio go-librespot[2553]: go-librespot daemon starting... Apr 15 11:53:53 volumio go-librespot[2553]: time="2026-04-15T11:53:53+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:53 volumio go-librespot[2553]: time="2026-04-15T11:53:53+03:00" level=debug msg="app state loaded" Apr 15 11:53:53 volumio go-librespot[2553]: time="2026-04-15T11:53:53+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=info msg="zeroconf server listening on port 36053" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="obtained new client token: AABU/KuUWVinrw/2xkTPUTYXxLTJtIAuRH2rFIy/8kc3/DD6GYqt4X+XKJfSGHzTQ2gWM6U2JtceYkIwZHNOwvT8RIGGibLF71AKfdFyFFefz3jdyeA2jZkaixxT+avlSRgcHivg5N/RodY1YfHhY+s+U+bG5A1ErM4txLNMCrvizonf0YbQDXh07zkUZDq0tzoY20CH3HapOpM1dynLA6Cmd8vd6wAuFf3UzNTToSl+wXJC1DmmCPBM" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=debug msg="completed challenge" Apr 15 11:53:54 volumio go-librespot[2553]: time="2026-04-15T11:53:54+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:55 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:55 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:53:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:53:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Apr 15 11:53:57 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:53:57 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:53:57 volumio go-librespot[2570]: go-librespot daemon starting... Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="app state loaded" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=info msg="zeroconf server listening on port 34587" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="obtained new client token: AADC4pWLMjdoNmtt9+cikT5PY9YSLzqx+31CJqU09UlDanJjqaq5zISZxFnqjz2Jvzw+WSGOMwjK8k0C3IsBEdpCCjo8aEGr2PylQAnEsgL6+tSGbfsBJws150XDn/p3WoXshZHlkhnWR2sn58wvj8644sgx5nC5h5AAbtEIvqgzK/bRPrFf0uR+az0NT0ujkMRBOmwC2UvIR7vB0kR74Q/ajJz9l4Ip+g3rfsapR6L2L4h/aAzff0QC5Oo=" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="completed keyexchange" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=debug msg="completed challenge" Apr 15 11:53:57 volumio go-librespot[2570]: time="2026-04-15T11:53:57+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:53:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:53:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:53:58 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:53:58 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Apr 15 11:54:01 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:01 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:01 volumio go-librespot[2584]: go-librespot daemon starting... Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="app state loaded" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=info msg="zeroconf server listening on port 37035" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="obtained new client token: AABfXZW5v1pfbOPolI9nVB6ZPdUJljJcNDWgIq4A7vdRJTN2f4weaSQU0sOcInesVmpmDHVfTaDMbcTyCdMlNyy7tZP+VopYOaP5uBZwCYvjpKm4bMS03sEDLTFOQKuoXNksXbfGTT8oUtQ6qUNxFQEL8QOGbx3xT6I27HHf2yw6Il2sfe2DRvs9823BcM7kNT3Pw7BYnnygNWY8EaeHcoa4kGfyryQwdnjHGFALOHmENTa9JfB7xdS0nJQ=" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=debug msg="completed challenge" Apr 15 11:54:01 volumio go-librespot[2584]: time="2026-04-15T11:54:01+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:01 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:01 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Apr 15 11:54:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:04 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:04 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:04 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:04 volumio go-librespot[2614]: go-librespot daemon starting... Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=debug msg="app state loaded" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=info msg="zeroconf server listening on port 34837" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=debug msg="obtained new client token: AACuoHQ+eoU/b0NssDamXqMMTNr/W4EWSYybkoIEKW89nyFL8L8dNMAny/O0PacQJmKTV+koYbxxCXVFW0l/obDnopo5B9N560j/gqrpg5SC6vZ6JulsHsgYRO3znR+S57NXo2cdkUNn1735cW8JkcxVVaVeM5Xg5ciXaDcoayIdduRM7dO1n5Ig1yqKLYr7fFVoEjaHybhxv/aX8ez+eNvZO3rWcfjP/hSkGlWAATexgcctU1aV6qax00Q=" Apr 15 11:54:04 volumio go-librespot[2614]: time="2026-04-15T11:54:04+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:05 volumio go-librespot[2614]: time="2026-04-15T11:54:05+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:05 volumio go-librespot[2614]: time="2026-04-15T11:54:05+03:00" level=debug msg="completed challenge" Apr 15 11:54:05 volumio go-librespot[2614]: time="2026-04-15T11:54:05+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:07 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:07 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:07 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 15 11:54:07 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 11:54:07 volumio volumio[801]: info: Preload queue cleared Apr 15 11:54:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Apr 15 11:54:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:08 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:08 volumio go-librespot[2628]: go-librespot daemon starting... Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="app state loaded" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=info msg="zeroconf server listening on port 43337" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="obtained new client token: AABnsKrMH/tGvIwoIvjrhtsL7iuQ2j9cEwbIxb6/BnKtQMMgeerNa5R5oXmHg4YbJyTpRZQWB6NhCoKmBme149fZo/hH7yks42R+fKxI4i1AqZFDKAACLPN//Y8P0qr1q81Srh9D/78WvxRyvlteTdcVOb5uXZAnhOkQbHN5xHqnOXbL2v0NTSq92n2YEQVnAv198NuhkA9sHtu9hk1GB4axEaviin+e0yR5UwthceR2+P50hCSaM2p8eM8=" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=debug msg="completed challenge" Apr 15 11:54:08 volumio go-librespot[2628]: time="2026-04-15T11:54:08+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:10 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:10 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Apr 15 11:54:11 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:11 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:11 volumio go-librespot[2644]: go-librespot daemon starting... Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="app state loaded" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=info msg="zeroconf server listening on port 42929" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="obtained new client token: AAC0sASiyTCP/Bap18hJEnXPCom5eROyf7F08XjED0Vw78lmcrJ3XGqneGw3W71o2BfYSMoLZZGIAL9y5YjaLI4OQmVIKe4Dgyzps5Iekwmzy8BkOkuO/SlVvJ2wUEACfgxxubpX0rzl4RIyv83d6+FOEyzzMFEytBEVjzE9HR2IS8vNlSNt754tHHxd3lKflYACGXDwJxp6NLp6J31LFWCjzoTa9FZuNoLTRb8JvdeD7C8W49TooYPa+5w=" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:11 volumio go-librespot[2644]: time="2026-04-15T11:54:11+03:00" level=debug msg="completed challenge" Apr 15 11:54:12 volumio go-librespot[2644]: time="2026-04-15T11:54:12+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:13 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:13 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Apr 15 11:54:15 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:15 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:15 volumio go-librespot[2673]: go-librespot daemon starting... Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="app state loaded" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:15 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=info msg="zeroconf server listening on port 34433" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="obtained new client token: AACIHHEulntCD07wCvhhkMo3B4vwXUt71m354Ae5nJFofGdVM19Z+UPqFIRISRhfCDwwU2kR1jzDYAxGSMcQ4TVDyO18mlXZO9N6W7mBdJD0BoFy/x+CHRZ1adFNZMAt2pb7Ha4dVlqboB2erjBBBsnStYevuxsvFpaqSIYo9MpJm8Qfh08qhs4uk/n4Gdbzjl74XHAp3+9iIGWxA+KKhUvHG+YtXynwgXutUHN9K8oyVmKhovzrurp239U=" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=debug msg="completed challenge" Apr 15 11:54:15 volumio go-librespot[2673]: time="2026-04-15T11:54:15+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:15 volumio volumio[801]: info: Preload queue cleared Apr 15 11:54:16 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:16 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Apr 15 11:54:18 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:18 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:18 volumio go-librespot[2689]: go-librespot daemon starting... Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=debug msg="app state loaded" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=info msg="zeroconf server listening on port 38547" Apr 15 11:54:18 volumio go-librespot[2689]: time="2026-04-15T11:54:18+03:00" level=debug msg="obtained new client token: AABvlye3J0/B+XvWWOgBx0BbSzf9gkV2ZlvutXv7QS/PANEWMssRoy9MwhdnmZUacgFpXrSHfAP8pa0y85wO28EqWZwWSSjM2gJQqYWlK+IcTK5Mh8HFRKy5aif2vcI6psE4MPg6B4ZeLO1GMlXNm+hPCGkNaKYeY/Tif9U7e6rJeO2Akra20bRXHQ5nS1GFf3cZmjuyf6frJlAWOT2/osfSVY+hou6Gotd+6PB572oQoRsP2BEdsYrV3So=" Apr 15 11:54:19 volumio go-librespot[2689]: time="2026-04-15T11:54:19+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:19 volumio go-librespot[2689]: time="2026-04-15T11:54:19+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:19 volumio go-librespot[2689]: time="2026-04-15T11:54:19+03:00" level=debug msg="completed challenge" Apr 15 11:54:19 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:19 volumio go-librespot[2689]: time="2026-04-15T11:54:19+03:00" level=debug msg="new websocket client" Apr 15 11:54:19 volumio volumio[801]: info: Connection to go-librespot Websocket established Apr 15 11:54:19 volumio go-librespot[2689]: time="2026-04-15T11:54:19+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:19 volumio volumio[801]: info: Connection to go-librespot Websocket closed Apr 15 11:54:22 volumio volumio[801]: info: Getting Spotify volume Apr 15 11:54:22 volumio volumio[801]: (node:801) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:22 volumio volumio[801]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 15 11:54:22 volumio volumio[801]: (node:801) 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: 6) Apr 15 11:54:22 volumio volumio[801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 15 11:54:22 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 15 11:54:22 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:22 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:22 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Apr 15 11:54:22 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:22 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:22 volumio go-librespot[2719]: go-librespot daemon starting... Apr 15 11:54:22 volumio go-librespot[2719]: time="2026-04-15T11:54:22+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:22 volumio go-librespot[2719]: time="2026-04-15T11:54:22+03:00" level=debug msg="app state loaded" Apr 15 11:54:22 volumio go-librespot[2719]: time="2026-04-15T11:54:22+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=info msg="zeroconf server listening on port 40015" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="obtained new client token: AAByZ3OET48KFrWpv1l23cP9ZZbZur7PNEqQVVRpoD6HZ4BfWBBoQxqk/yj0/X3XuAnOqaf/awEpeIXxbfPSaoPbXEK3jEumdxhUagYsabg796liOIZew1/cJDe6/FBuw7IHj9kk4ltIq3cNMr9LjJcmovY9gZlrnEFBX0oJSj+gYbIIMLNx14HD265+D5JIl34wQ81HFkBMwO6pMuImFEe0HPjXWAS8aECXrx7Kmnn178Ujcz3I0huD" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=debug msg="completed challenge" Apr 15 11:54:23 volumio go-librespot[2719]: time="2026-04-15T11:54:23+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:25 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:25 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Apr 15 11:54:26 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:26 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:26 volumio go-librespot[2773]: go-librespot daemon starting... Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=debug msg="app state loaded" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=info msg="zeroconf server listening on port 43023" Apr 15 11:54:26 volumio go-librespot[2773]: time="2026-04-15T11:54:26+03:00" level=debug msg="obtained new client token: AAB3sYBNyZA0F6ZZL4MbhrgC+Lqdfhf9y5jldoUe4zYHNytk/1q+hXraCdZuAE1gk/cA9nL4DpTeeo3HFFTkigiDaRwC6uHuPpeUK/xzzgXjKlnN5Re8LYl+im14VPYic4V5CPEVKBJl8fcTERfLcW5eCfQvmE/Rwe4nGbOVooXkGDVfjtkNwDIvqYxUIp2EvA5i+A7maWCILVyM6tpqfuDcrvDZ9jlcwX/ES32WauXSmkFGSITRUYRo5IM=" Apr 15 11:54:27 volumio go-librespot[2773]: time="2026-04-15T11:54:27+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:27 volumio go-librespot[2773]: time="2026-04-15T11:54:27+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:27 volumio go-librespot[2773]: time="2026-04-15T11:54:27+03:00" level=debug msg="completed challenge" Apr 15 11:54:27 volumio go-librespot[2773]: time="2026-04-15T11:54:27+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:28 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:28 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Apr 15 11:54:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:30 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:30 volumio go-librespot[2787]: go-librespot daemon starting... Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="app state loaded" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=info msg="zeroconf server listening on port 38151" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="obtained new client token: AAD+7o087dCIXvUVnW3oVGEyYOXLLldReJzOjFHy4TrgDObd/2GhaRHKGrrIJYf5wXFkiozJLfRp19dG9j7+R/Z36ZkS2CreZzguDgvhw02AXtK7GWfW5YlZhp4Ed/ylfuz9Edl6rZY64hYbT4VCizMAcKgy+jnOb5m9ARj4n9eMRBkmLdBL+6Rua0CaCr2sY4XZP4ZZyT0owtZFV3vBy+kRagx9S7qjtTsMjmhJXgrkNETqw08ylKEikDI=" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=debug msg="completed challenge" Apr 15 11:54:30 volumio go-librespot[2787]: time="2026-04-15T11:54:30+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:31 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:31 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Apr 15 11:54:34 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:34 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:34 volumio go-librespot[2818]: go-librespot daemon starting... Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="app state loaded" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=info msg="zeroconf server listening on port 37293" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="obtained new client token: AAAM74Z33/j0NnaFOlw10TJIiZTTlmPgQb5h+6nyyLXgIp62PCYiDV2h+gfEXdwXFG/5a9Llh+GQ2+lHGp4vPOOnB/B/57ekqGk7/0iihYPmV74rtftjuy8cW2PwL6oKavthJXRXIwRbAhowXKtZ/D0X9Anbb0G50rlwog/XI7AKjhbDVU07JUCkk6P+vHeEteILBNZWDHdcJUevW4PxXYJhFOLt3r0S9gXhB1a8qzi4aytYXawPCvvpH1g=" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=debug msg="completed challenge" Apr 15 11:54:34 volumio go-librespot[2818]: time="2026-04-15T11:54:34+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:34 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:34 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:37 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:37 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Apr 15 11:54:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:37 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:37 volumio go-librespot[2835]: go-librespot daemon starting... Apr 15 11:54:37 volumio go-librespot[2835]: time="2026-04-15T11:54:37+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:37 volumio go-librespot[2835]: time="2026-04-15T11:54:37+03:00" level=debug msg="app state loaded" Apr 15 11:54:37 volumio go-librespot[2835]: time="2026-04-15T11:54:37+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=info msg="zeroconf server listening on port 42779" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="obtained new client token: AAB23XiF10tZxPKKR55GQ0VRa0LhpB3Iim9bzzHAnDYzlA4CPogiRjrdIO7ZYqewXoBBUMCwdYOpG7AMSWSG7rNBxRewCQiYUqmWHZC1DZmPQFjj3yf8/y6+67XBVKzNgMy4/dcE8/ovVSK5lwTXen4xKh1NN65ETnFTep6GeMxZX3SgaC5OXcgukyHV1jeeG3di0WoVFjX5Y9kVY/cJ4D5SYx9eUlbFlr6GNOFnH89/t4IvXPVNP6Yg" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=debug msg="completed challenge" Apr 15 11:54:38 volumio go-librespot[2835]: time="2026-04-15T11:54:38+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:40 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:40 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Apr 15 11:54:41 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:41 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:41 volumio go-librespot[2849]: go-librespot daemon starting... Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="app state loaded" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=info msg="zeroconf server listening on port 42891" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="obtained new client token: AACPxpzWwcv1dv93mqZSmjRodvW8RaQn3H21Bhz4Hb2m6IyHd5IBLR+AdHtbMn7sdk0veO6bdX9tl/5Ggbnly5Xh4YBDft3TNLWXsZDBJAqd2KFu81pFdvFNGmiwE7bkwXuEWpVZjJvJlvOeYKMXv5RuzqINza+He9etjilCijQXgLnc/8zQZenIaHo3Rr+ZXMoCBJZxwZ4bBNDLsazx3jYhTqktcG54VYID7xUbLEhItAG1I76Nma2ENuA=" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=debug msg="completed challenge" Apr 15 11:54:41 volumio go-librespot[2849]: time="2026-04-15T11:54:41+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:43 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:43 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:44 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 15 11:54:44 volumio volumio[801]: info: Preload queue cleared Apr 15 11:54:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Apr 15 11:54:44 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:44 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:44 volumio go-librespot[2879]: go-librespot daemon starting... Apr 15 11:54:44 volumio go-librespot[2879]: time="2026-04-15T11:54:44+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:44 volumio go-librespot[2879]: time="2026-04-15T11:54:44+03:00" level=debug msg="app state loaded" Apr 15 11:54:44 volumio go-librespot[2879]: time="2026-04-15T11:54:44+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=info msg="zeroconf server listening on port 37235" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="obtained new client token: AACyeqFGJpPp8bY8JgEvovAopMXQVJcK8XUf38w/JrV+YWhfSgUBBEjebyu1tjK3Oz+89IzEGHdjvOApODCxf/JC0u5a085s9tFw/Qge2rtWTkwU/Oc8RgOyZ3qWNMtBgEidN+uBYyDtPH7zjykierybarh6/3tNMW9a6lWf0fkS5K05QWEibFV6yVypv0Ks1Rbooox9Q/Y62Qe1hAja7NpV0xsQibNUejrzzeVFnPqLLk4aH7sqrNR5" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=debug msg="completed challenge" Apr 15 11:54:45 volumio go-librespot[2879]: time="2026-04-15T11:54:45+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:45 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 15 11:54:45 volumio volumio[801]: info: Preload queue cleared Apr 15 11:54:46 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:46 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:47 volumio volumio[801]: info: Preload queue cleared Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::ClearQueue Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::stop Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::stPlaybackTimer Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::serviceStop Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::serviceStop Apr 15 11:54:47 volumio volumio[801]: info: ControllerMpd::stop Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::clearPlayQueue Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::addQueueItems Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::addQueueItems Apr 15 11:54:47 volumio volumio[801]: info: Preload queue cleared Apr 15 11:54:47 volumio volumio[801]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320 Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::play index 0 Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::stop Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::startPlaybackTimer Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: [1776243287761] ControllerWebradio::clearAddPlayTrack Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 11:54:47 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:54:47 volumio volumio[801]: info: [GPIO_Control] Handling event: musicStop Apr 15 11:54:47 volumio volumio[801]: info: Apr 15 11:54:47 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand stop took 25 milliseconds Apr 15 11:54:47 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand stop took 6 milliseconds Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clear Apr 15 11:54:47 volumio volumio[801]: info: Apr 15 11:54:47 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:47 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:47 volumio volumio[801]: info: Apr 15 11:54:47 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:47 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:47 volumio volumio[801]: info: Apr 15 11:54:47 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:47 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand clear took 4 milliseconds Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:47 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 15 11:54:47 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:47 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:47 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:47 volumio volumio[801]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 15 11:54:47 volumio volumio[801]: info: ------------------------------ 24ms Apr 15 11:54:47 volumio volumio[801]: info: ------------------------------ 23ms Apr 15 11:54:47 volumio volumio[801]: info: Apr 15 11:54:47 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:47 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:47 volumio volumio[801]: info: Apr 15 11:54:47 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:47 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:47 volumio volumio[801]: error: updateQueue error: null Apr 15 11:54:47 volumio volumio[801]: info: ------------------------------ 25ms Apr 15 11:54:47 volumio volumio[801]: info: sendMpdCommand playlistinfo took 24 milliseconds Apr 15 11:54:47 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:47 volumio volumio[801]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 15 11:54:47 volumio volumio[801]: info: ------------------------------ 30ms Apr 15 11:54:47 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:54:47 volumio volumio[801]: info: [GPIO_Control] Status changed: stop Apr 15 11:54:48 volumio volumio[801]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" took 560 milliseconds Apr 15 11:54:48 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 15 11:54:48 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand play Apr 15 11:54:48 volumio volumio[801]: info: Apr 15 11:54:48 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:48 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:48 volumio volumio[801]: info: ------------------------------ 542ms Apr 15 11:54:48 volumio volumio[801]: info: ------------------------------ 541ms Apr 15 11:54:48 volumio volumio[801]: info: sendMpdCommand play took 2 milliseconds Apr 15 11:54:48 volumio volumio[801]: info: Apr 15 11:54:48 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:48 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:48 volumio volumio[801]: info: Apr 15 11:54:48 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:48 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:48 volumio volumio[801]: info: ------------------------------ 4ms Apr 15 11:54:48 volumio volumio[801]: info: ------------------------------ 2ms Apr 15 11:54:48 volumio volumio[801]: info: ------------------------------ 1ms Apr 15 11:54:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 15 11:54:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Apr 15 11:54:48 volumio systemd[1]: Stopped go-librespot Daemon. Apr 15 11:54:48 volumio systemd[1]: Started go-librespot Daemon. Apr 15 11:54:48 volumio go-librespot[2897]: go-librespot daemon starting... Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=info msg="running go-librespot 0.4.0" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=debug msg="app state loaded" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=info msg="zeroconf server listening on port 40939" Apr 15 11:54:48 volumio go-librespot[2897]: time="2026-04-15T11:54:48+03:00" level=debug msg="obtained new client token: AAD5YnKnaIF0pNv7iGnSJmiz6NCvtzenjrCPEL6ahAyAHiiJxX/VlIiHmGxHPn+nURrGv2z9TnKMGoPr7JtpOMxRcx98NP0rdseXF5NSRtKNztuMnhJnKBU4Ufu6bD4mTqYCnBCYBamOJ84ogFX6U59cCSuBPV5bUZJ0/ruqwBVdmWKUjyPdJutxx+/qYvqK3PDkV/J85rKdtak2gj73tL5qfjNbvKpMWUOmU8QjU10DUQEV9gCTdIf1N5Q=" Apr 15 11:54:49 volumio go-librespot[2897]: time="2026-04-15T11:54:49+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 15 11:54:49 volumio go-librespot[2897]: time="2026-04-15T11:54:49+03:00" level=debug msg="completed keyexchange" Apr 15 11:54:49 volumio go-librespot[2897]: time="2026-04-15T11:54:49+03:00" level=debug msg="completed challenge" Apr 15 11:54:49 volumio go-librespot[2897]: time="2026-04-15T11:54:49+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 15 11:54:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 15 11:54:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 15 11:54:49 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 15 11:54:49 volumio volumio[801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 4 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 6 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 1 milliseconds Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 8314/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 8314/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 8314/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 25ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 46ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 44ms Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:50 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 36 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 36 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 8314/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 8314/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 8314/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 86ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 82ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 81ms Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Handling event: musicPlay Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:50 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:50 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:50 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 68ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 66 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 4ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 3ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:50 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 15 11:54:50 volumio volumio[801]: info: Ignoring MPD Status Update Apr 15 11:54:50 volumio volumio[801]: info: Apr 15 11:54:50 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::getState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 6ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 5 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 4ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 3 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 3ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand status took 2 milliseconds Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 120ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 57ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 57ms Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 49 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 47 milliseconds Apr 15 11:54:50 volumio volumio[801]: info: sendMpdCommand playlistinfo took 46 milliseconds Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ControllerMpd::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 15 11:54:50 volumio volumio[801]: info: CorePlayQueue::getTrack 0 Apr 15 11:54:50 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 15 11:54:50 volumio volumio[801]: verbose: CURRENT POSITION 0 Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 15 11:54:50 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: CoreStateMachine::pushState Apr 15 11:54:50 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 100ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 98ms Apr 15 11:54:50 volumio volumio[801]: info: ------------------------------ 97ms Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:50 volumio volumio[801]: info: [GPIO_Control] Status changed: play Apr 15 11:54:51 volumio volumio[801]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 11:54:51 volumio volumio[801]: TypeError: Cannot read property 'slice' of null Apr 15 11:54:51 volumio volumio[801]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Apr 15 11:54:51 volumio volumio[801]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Apr 15 11:54:51 volumio volumio[801]: at Object.onceWrapper (events.js:422:26) Apr 15 11:54:51 volumio volumio[801]: at ClientRequest.emit (events.js:315:20) Apr 15 11:54:51 volumio volumio[801]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Apr 15 11:54:51 volumio volumio[801]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Apr 15 11:54:51 volumio volumio[801]: at TLSSocket.socketOnData (_http_client.js:509:22) Apr 15 11:54:51 volumio volumio[801]: at TLSSocket.emit (events.js:315:20) Apr 15 11:54:51 volumio volumio[801]: at addChunk (internal/streams/readable.js:309:12) Apr 15 11:54:51 volumio volumio[801]: at readableAddChunk (internal/streams/readable.js:284:9) Apr 15 11:54:51 volumio volumio[801]: at TLSSocket.Readable.push (internal/streams/readable.js:223:10) Apr 15 11:54:51 volumio volumio[801]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Apr 15 11:54:51 volumio volumio[801]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 11:54:51 volumio sudo[2920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-15 11:53 Apr 15 11:54:51 volumio sudo[2920]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"