Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 18:17:00 volumio-total volumio[1389]: info: Received Get System Info Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 18:17:00 volumio-total volumio[1389]: info: Discovery: Getting this device information Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:00 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 0 Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 18:17:00 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:00 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:00 volumio-total volumio[1389]: info: go-librespot daemon successfully initialized Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 30 18:17:00 volumio-total volumio[1389]: info: CURURI: playlists Aug 30 18:17:00 volumio-total volumio[1389]: info: Listing playlists Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetQueue Aug 30 18:17:00 volumio-total volumio[1389]: info: CoreStateMachine::getQueue Aug 30 18:17:00 volumio-total volumio[1389]: info: CorePlayQueue::getQueue Aug 30 18:17:00 volumio-total volumio[1389]: info: Listing playlists Aug 30 18:17:00 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:01 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 30 18:17:01 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:01 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:01 volumio-total go-librespot[2728]: go-librespot daemon starting... Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=debug msg="app state loaded" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02: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]" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02: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]" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02: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]" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=info msg="zeroconf server listening on port 37019" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=debug msg="obtained new client token: AAGE/v4tuHU4lfdkt2C2BOI98dgc2WwS99fVA5g2C8Tn1jKLb+6hMQUuTWcq0LYZPPavMLUqUZCTtFDU/JBDdYpK/qOt1j1/uO0mqEZrDrMC9fxa1bTS8M3woMLOL2ur9NHrGiqen4SbK0NY8Z5ZPOZEVxI3iT+zmaG0uRCn9BjdFdSP2GubevIV0Wg1RdC6XuBI48bHCjBPYxcNhpzNrQVA8vCv3INTqQAa7/gUp4qyqvKXuL+aDmLM+g==" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=debug msg="completed challenge" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:01 volumio-total go-librespot[2729]: time="2026-08-30T18:17:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:01 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:01 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:02 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 30 18:17:02 volumio-total volumio[1389]: info: CURURI: playlists/Ja Aug 30 18:17:02 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:02 volumio-total volumio[1389]: info: Preloading song: spotify:track:3dTGR2oQA1XaC850o5oPdK Aug 30 18:17:02 volumio-total volumio[1389]: info: Exploding uri spotify:track:3dTGR2oQA1XaC850o5oPdK in service spop Aug 30 18:17:02 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:3dTGR2oQA1XaC850o5oPdK Aug 30 18:17:02 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3dTGR2oQA1XaC850o5oPdK","service":"spop","name":"Hotel California","artist":"Eagles","album":"Hell Freezes Over","type":"song","duration":432,"albumart":"https://i.scdn.co/image/ab67616d0000b2732d1eaba068fdfe2a09e7ff9e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:03 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:03 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:03 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:03 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:04 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 30 18:17:04 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:04 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:04 volumio-total go-librespot[2738]: go-librespot daemon starting... Aug 30 18:17:04 volumio-total go-librespot[2739]: time="2026-08-30T18:17:04+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:04 volumio-total go-librespot[2739]: time="2026-08-30T18:17:04+02:00" level=debug msg="app state loaded" Aug 30 18:17:04 volumio-total go-librespot[2739]: time="2026-08-30T18:17:04+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:04 volumio-total go-librespot[2739]: time="2026-08-30T18:17:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02: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]" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02: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]" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02: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]" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=info msg="zeroconf server listening on port 39149" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=debug msg="obtained new client token: AAHRSdOXOSpem2ecUWuO9ExEu+K0gEM/1db1wvmwLsUT4wNMLUvJJw48/yc/bfWJGzatizZeWyobMzKgmNVvEEul8/GX+m8jCSLk//49pxdbAiQwzJ1TUY2nqdv6tD0Ll+3J8/nRVOBxs4EsMoflrXuT3EIMWCJD3iHwIahYaCyhIwLajOq4uZ/8vI9ezDB1fai7e1Gia7Xf/tETKXrnAPk8wZbcVRKgWQ3SJcxWfvLReHJhmmmJ8u4=" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:05 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 30 18:17:05 volumio-total volumio[1389]: info: CURURI: artists:// Aug 30 18:17:05 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=debug msg="completed challenge" Aug 30 18:17:05 volumio-total go-librespot[2739]: time="2026-08-30T18:17:05+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:06 volumio-total go-librespot[2739]: time="2026-08-30T18:17:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:06 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:06 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:06 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 30 18:17:06 volumio-total volumio[1389]: info: CURURI: albums:// Aug 30 18:17:06 volumio-total volumio[1389]: info: listAlbums - loading Albums from cache Aug 30 18:17:06 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:06 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:06 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:08 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 30 18:17:08 volumio-total volumio[1389]: info: UPNP Browser: No servers found, reinitializing and searching... Aug 30 18:17:09 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 30 18:17:09 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:09 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:09 volumio-total go-librespot[2764]: go-librespot daemon starting... Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=debug msg="app state loaded" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02: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]" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02: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]" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02: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]" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=info msg="zeroconf server listening on port 36519" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=debug msg="obtained new client token: AAGCv4616s/Zl004zGKfAROsNKOsCAR3+jkOD5DOt0kwcjMxoDUbNIy8kaNg9z/lvxSqmxAjDHJKgbFPDy5J+PEbucJTNilNFyjjE1a4QsOSkSaIZVwIDjk8xiOtX0y3PvJ3k+n4PL1QTa1B3GJEhECrTvSXRgAfHUNWJP/ep4cqYJZx4iyeqvsGlE9NFO9JABMpfhpOpDF5pOXMFQ5MC5QYhD/FZPFTf8pD1RgUpyXaBM86hEp4VNi6Ng==" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=debug msg="completed challenge" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:09 volumio-total go-librespot[2765]: time="2026-08-30T18:17:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:09 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:09 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:09 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:09 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:10 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 30 18:17:10 volumio-total volumio[1389]: info: In handleBrowseUri, curUri=spotify Aug 30 18:17:10 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:10 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:10 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:10 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:11 volumio-total volumio[1389]: info: UPNP Browser: Returning 0 server(s) after 3s wait Aug 30 18:17:11 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:12 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:12 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:12 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 30 18:17:12 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:12 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:12 volumio-total go-librespot[2774]: go-librespot daemon starting... Aug 30 18:17:12 volumio-total go-librespot[2775]: time="2026-08-30T18:17:12+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:12 volumio-total go-librespot[2775]: time="2026-08-30T18:17:12+02:00" level=debug msg="app state loaded" Aug 30 18:17:12 volumio-total go-librespot[2775]: time="2026-08-30T18:17:12+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:12 volumio-total go-librespot[2775]: time="2026-08-30T18:17:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02: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]" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02: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]" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02: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]" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=info msg="zeroconf server listening on port 44903" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=debug msg="obtained new client token: AAHNqetR1KwyTHr+LN99Kjsdhh/MSKnF8Kq85xGW/UDojRog8m0Hew+gbOBV75jzsn9XM8okrt37Okn717YITfjQj/1kkPu6BMCF6P4nog+CXYn3eUJAWn1/xKBE0JSaPpg5/wVl/1SNPyv0TeS6Kfe+Ic+nivuK7iGIi8+dNyl8cxgziKBSlSwL3Odsoh/BSrZldW9c56Y9soZkbViOOjrP55LPSDOIZHko5M0pwsPxk6l6Pxqjd1Q=" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02: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" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=debug msg="completed challenge" Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:13 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 30 18:17:13 volumio-total volumio[1389]: info: In handleBrowseUri, curUri=spotify Aug 30 18:17:13 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:13 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:13 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:13 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:13 volumio-total go-librespot[2775]: time="2026-08-30T18:17:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:13 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:13 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:13 volumio-total volumio[1389]: info: Tunnel connection is inactive, restarting it Aug 30 18:17:13 volumio-total volumio[1389]: info: Starting Tunnel 1 Aug 30 18:17:13 volumio-total volumio[1389]: info: Starting Tunnel Connection Checker Aug 30 18:17:13 volumio-total sudo[2790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Aug 30 18:17:13 volumio-total sudo[2790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 18:17:13 volumio-total autossh[2431]: received signal to exit (15) Aug 30 18:17:13 volumio-total systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Aug 30 18:17:13 volumio-total systemd[1]: sshtunnel.service: Deactivated successfully. Aug 30 18:17:13 volumio-total systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:13 volumio-total systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:13 volumio-total sudo[2790]: pam_unix(sudo:session): session closed for user root Aug 30 18:17:13 volumio-total volumio[1389]: info: Remote SSH Started Aug 30 18:17:13 volumio-total autossh[2793]: port set to 0, monitoring disabled Aug 30 18:17:13 volumio-total autossh[2793]: starting ssh (count 1) Aug 30 18:17:13 volumio-total autossh[2793]: ssh child pid is 2796 Aug 30 18:17:13 volumio-total volumio[1389]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Aug 30 18:17:13 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:13 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 0 Aug 30 18:17:13 volumio-total volumiossh-tunnel[2796]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 30 18:17:13 volumio-total autossh[2793]: ssh exited prematurely with status 255; autossh exiting Aug 30 18:17:13 volumio-total systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:13 volumio-total systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 30 18:17:13 volumio-total systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 1. Aug 30 18:17:13 volumio-total systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:13 volumio-total systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:13 volumio-total autossh[2798]: port set to 0, monitoring disabled Aug 30 18:17:13 volumio-total autossh[2798]: starting ssh (count 1) Aug 30 18:17:13 volumio-total autossh[2798]: ssh child pid is 2801 Aug 30 18:17:13 volumio-total volumiossh-tunnel[2801]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 30 18:17:13 volumio-total autossh[2798]: ssh exited prematurely with status 255; autossh exiting Aug 30 18:17:13 volumio-total systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:13 volumio-total systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 2. Aug 30 18:17:14 volumio-total systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total autossh[2803]: port set to 0, monitoring disabled Aug 30 18:17:14 volumio-total autossh[2803]: starting ssh (count 1) Aug 30 18:17:14 volumio-total autossh[2803]: ssh child pid is 2806 Aug 30 18:17:14 volumio-total volumiossh-tunnel[2806]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 30 18:17:14 volumio-total autossh[2803]: ssh exited prematurely with status 255; autossh exiting Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 3. Aug 30 18:17:14 volumio-total systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total autossh[2808]: port set to 0, monitoring disabled Aug 30 18:17:14 volumio-total autossh[2808]: starting ssh (count 1) Aug 30 18:17:14 volumio-total autossh[2808]: ssh child pid is 2811 Aug 30 18:17:14 volumio-total volumiossh-tunnel[2811]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 30 18:17:14 volumio-total autossh[2808]: ssh exited prematurely with status 255; autossh exiting Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 4. Aug 30 18:17:14 volumio-total systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total autossh[2813]: port set to 0, monitoring disabled Aug 30 18:17:14 volumio-total autossh[2813]: starting ssh (count 1) Aug 30 18:17:14 volumio-total autossh[2813]: ssh child pid is 2816 Aug 30 18:17:14 volumio-total volumiossh-tunnel[2816]: ssh: connect to host eu6.myvolumio.org port 2222: Connection refused Aug 30 18:17:14 volumio-total autossh[2813]: ssh exited prematurely with status 255; autossh exiting Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 5. Aug 30 18:17:14 volumio-total systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Start request repeated too quickly. Aug 30 18:17:14 volumio-total systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Aug 30 18:17:14 volumio-total systemd[1]: Failed to start sshtunnel.service - MyVolumio SSH Tunnel. Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 18:17:15 volumio-total volumio[1389]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 30 18:17:15 volumio-total volumio[1389]: info: Received Get System Version Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 18:17:15 volumio-total volumio[1389]: info: Received Get System Info Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 18:17:15 volumio-total volumio[1389]: info: Discovery: Getting this device information Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:15 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 0 Aug 30 18:17:15 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 18:17:15 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:15 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:16 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 30 18:17:16 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:16 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:16 volumio-total go-librespot[2817]: go-librespot daemon starting... Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=debug msg="app state loaded" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02: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]" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02: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]" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02: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]" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=info msg="zeroconf server listening on port 38149" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=debug msg="obtained new client token: AAGl5JN/h5/VAEjvGNSPzbvjSyGQ5SVieRc0RTiLlRvxZ/EKaakfXigt9RWr15LWt8hvHqPByg5IOL0H5S8BFbGQctAQc1XR28pgvRb7ewIXKas2uLFeHhrNbBW3ZrFa+eJFM08f0Qb9LDZac/FUoE631aOjan8ZbxRZIioBPnv0cF/2ghitmTmiYtF/ahIPSfyaSWXOZDbgkasxA91jTpmLf6iGq5sOBHRulkReStpsyQTdUnAl4AR1xw==" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=debug msg="completed challenge" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:16 volumio-total go-librespot[2818]: time="2026-08-30T18:17:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:16 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:16 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:17 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 30 18:17:17 volumio-total volumio[1389]: info: In handleBrowseUri, curUri=spotify/playlists Aug 30 18:17:17 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:18 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:18 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:19 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 30 18:17:19 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:19 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:19 volumio-total go-librespot[2842]: go-librespot daemon starting... Aug 30 18:17:19 volumio-total go-librespot[2843]: time="2026-08-30T18:17:19+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:19 volumio-total go-librespot[2843]: time="2026-08-30T18:17:19+02:00" level=debug msg="app state loaded" Aug 30 18:17:19 volumio-total go-librespot[2843]: time="2026-08-30T18:17:19+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:19 volumio-total go-librespot[2843]: time="2026-08-30T18:17:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02: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]" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02: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]" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02: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]" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=info msg="zeroconf server listening on port 34789" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=debug msg="obtained new client token: AAEyroA6oR/sllCPat8nI3CllYG6a6wMIAD1ARJCYVnUwcpX/ANdUeqT+7xQvZ1D90NKPTy+j5PEAMgqB7qJUawfu6PxDvBC13MwOFF216FE/wTju9A5Ho9M+VAOJJRIWKYr1X88JzhaiNNpbqh6PYvqXSgA7zhIPGVTZbdu34hbAaCHlFGx9i3DifCzy6rtYxj6ocC5g1VkcFcPNqhPKunvSRjA//ur47RmrqTKUPXaZvSZ8hih9FE=" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=debug msg="completed challenge" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:20 volumio-total go-librespot[2843]: time="2026-08-30T18:17:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:20 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:20 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:21 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:21 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:23 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 30 18:17:23 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:23 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:23 volumio-total go-librespot[2854]: go-librespot daemon starting... Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=debug msg="app state loaded" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02: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]" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02: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]" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02: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]" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=info msg="zeroconf server listening on port 40089" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=debug msg="obtained new client token: AAEmGG9GFR5WG32EAYAk1xyEU4PDZPn/26oAxteYdCVvY4YNEmpuktcRt02/xDvwZwOHm8vrxzhkZQnworSxJRHVskP85qRTqLde0tMqF0u0t1xYGfTQlkPDxIOqcwaAK+ozZipr7hXx9WTFAhh1X8t03kLQanICOAUkGxdlTWyAKqVr28Izjj/YGY3CCBjj7kOQvi7HY6SNQfXG9TL0dxln+ebfcjh4ZDgHGC4iR0B8EMc+U2TSXZgEUA==" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=debug msg="completed challenge" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:23 volumio-total go-librespot[2855]: time="2026-08-30T18:17:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:23 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:23 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:24 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:24 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:26 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 30 18:17:26 volumio-total volumio[1389]: info: In handleBrowseUri, curUri=spotify/mytracks Aug 30 18:17:26 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:26 volumio-total volumio[1389]: info: Preloading song: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:26 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 30 18:17:26 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:26 volumio-total volumio[1389]: info: Exploding uri spotify:track:7CByuZeDV4syW8O8hPVAnF in service spop Aug 30 18:17:26 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:26 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:26 volumio-total go-librespot[2864]: go-librespot daemon starting... Aug 30 18:17:26 volumio-total go-librespot[2865]: time="2026-08-30T18:17:26+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:26 volumio-total go-librespot[2865]: time="2026-08-30T18:17:26+02:00" level=debug msg="app state loaded" Aug 30 18:17:26 volumio-total go-librespot[2865]: time="2026-08-30T18:17:26+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:26 volumio-total go-librespot[2865]: time="2026-08-30T18:17:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:26 volumio-total volumio[1389]: info: Exploding uri spotify:track:3l2YonZos6mqb4u2rwk2zr in service spop Aug 30 18:17:26 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:27 volumio-total volumio[1389]: info: Exploding uri spotify:track:3bMs6bUPpeRgXY5tDmNXZU in service spop Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02: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]" Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02: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]" Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02: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]" Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=info msg="zeroconf server listening on port 45323" Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3l2YonZos6mqb4u2rwk2zr","service":"spop","name":"Voilà - Live","artist":"Barbara Pravi","album":"Love Is All Around (Live)","type":"song","duration":332,"albumart":"https://i.scdn.co/image/ab67616d0000b27356fa92a901092ae6cd2dc946","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: info: Exploding uri spotify:track:4yozol821zh2HhcIPiFuTV in service spop Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7CByuZeDV4syW8O8hPVAnF","service":"spop","name":"Earth Song - Live in Maastricht 2025","artist":"Michael Jackson","album":"Waltz the Night Away! (Live in Maastricht 2025)","type":"song","duration":341,"albumart":"https://i.scdn.co/image/ab67616d0000b2738d3536efe4716e0a1836f3db","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: info: Exploding uri spotify:track:2AG5zv50AkMMct4nZk9q2k in service spop Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=debug msg="obtained new client token: AAGbK4eCP+QDUOTnbRS47FrIPeH8uTCF4laVcdk/TuIZO5ZsZmiNqGMpt9xKWNyKMMH2RetINHa/J51/0r2939SzsKgMFrishuAQ0liXgNSiPqISL4dlldg/MvdhAd3i3s0xV6Tg5toLzMWI+kRYtL3S2iG+pLGSdPdnXHE2CgOaB5Sd0aCgs1p3Iei4sUkofj9iZ0Q6zUjTRV9NsVit3R/rKKRFlzwowAS1owIgxmRhf7fWMHYjptY=" Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3bMs6bUPpeRgXY5tDmNXZU","service":"spop","name":"Dancing on the Stars - Live","artist":"Tjeerd P. Oosterhuis","album":"Dancing on the Stars (Live)","type":"song","duration":358,"albumart":"https://i.scdn.co/image/ab67616d0000b273dd68787d7820d8e36e3b93de","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: info: Exploding uri spotify:track:6BZD6qRbi1MfwBtFOTvDCh in service spop Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=debug msg="completed challenge" Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4yozol821zh2HhcIPiFuTV","service":"spop","name":"Strijder","artist":"Emma Kok","album":"Strijder","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b2734124146af949dea5db8b4f69","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2AG5zv50AkMMct4nZk9q2k","service":"spop","name":"Voilà - Live","artist":"Barbara Pravi","album":"Voilà (Live)","type":"song","duration":310,"albumart":"https://i.scdn.co/image/ab67616d0000b273fa7b5e11b1261f0681fd226c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: info: Exploding uri spotify:track:7tostJTMXhaRiVLTTXcvhe in service spop Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6BZD6qRbi1MfwBtFOTvDCh","service":"spop","name":"Euphoria - Live In Concertgebouw","artist":"Emma Kok","album":"Live In Concertgebouw","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b27330fcca80cb2331947ec6dc8f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: info: Exploding uri spotify:track:3DwQ7AH3xGD9h65ezslm6q in service spop Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: EXPLODING URI:spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:27 volumio-total go-librespot[2865]: time="2026-08-30T18:17:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:27 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:27 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7tostJTMXhaRiVLTTXcvhe","service":"spop","name":"Tattoo","artist":"Loreen","album":"WILDFIRE","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b27359e45447f908bf8827eb2b37","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3DwQ7AH3xGD9h65ezslm6q","service":"spop","name":"Enter Sandman - Remastered 2021","artist":"Metallica","album":"Metallica (Remastered Deluxe Box Set)","type":"song","duration":331,"albumart":"https://i.scdn.co/image/ab67616d0000b273c1a13209dfe146aef3296e34","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 30 18:17:27 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:27 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:30 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 30 18:17:30 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:30 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:30 volumio-total go-librespot[2889]: go-librespot daemon starting... Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=debug msg="app state loaded" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02: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]" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02: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]" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02: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]" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=info msg="zeroconf server listening on port 35037" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=debug msg="obtained new client token: AAGQFIh7ZcOnO5q8NNyKqXRQukJxbPNCb33Wpbdyq9FLk3vlMspkqQCoNGa486Ku/afTFp1+FxM3ReSt3h4eDjLY87GwKZk9NO6VzxjeY+Tnyp/tuLhfzj4ETOPRS1XMgiUUL3vvnxL1H5a36UtUTW60pZ5JbBdc+kJo/C09NBidsZPf1ldihFunQ1P/vXXFLM9p5kTstFwH2ypEznmxTRwXC4nwo8fmrr8XGbjD3cvvQ0XAFcrXmZAZHw==" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=debug msg="completed challenge" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:30 volumio-total go-librespot[2890]: time="2026-08-30T18:17:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:30 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:30 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:30 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:30 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:31 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:31 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 0 Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::play index 6 Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:31 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:31 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:31 volumio-total volumio[1389]: info: [1788106651071] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:31 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:31 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:33 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:33 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:33 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 30 18:17:33 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:33 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:33 volumio-total go-librespot[2899]: go-librespot daemon starting... Aug 30 18:17:33 volumio-total go-librespot[2900]: time="2026-08-30T18:17:33+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:33 volumio-total go-librespot[2900]: time="2026-08-30T18:17:33+02:00" level=debug msg="app state loaded" Aug 30 18:17:33 volumio-total go-librespot[2900]: time="2026-08-30T18:17:33+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:33 volumio-total go-librespot[2900]: time="2026-08-30T18:17:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02: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]" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02: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]" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02: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]" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=info msg="zeroconf server listening on port 43861" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=debug msg="obtained new client token: AAHSP5K+mS39aOVYDDnGakkaA32vA2iaAuzwaXwSuNFSFM/sp9XOJGj8IH1aEhl04nKDYV+bJSnF2Vqqnlkj+dhTyC7P0uVewNWNqkXL666QWD34ltCJkbQqdmOi/TkkRfd9psohQhUd6T6sVFMd83COA/wAXM/3Zdumy0IxS6pXEJYecS6XCG/YqjZj16oCnYCSKnP6gLjM4NpRFZ+vXuoPjD1m0v3coRH6D3hOSIk2chSv3B0siSA=" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=debug msg="completed challenge" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:34 volumio-total go-librespot[2900]: time="2026-08-30T18:17:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:34 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:34 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:34 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:34 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::play index 6 Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:34 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:34 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:34 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:34 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:34 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:34 volumio-total volumio[1389]: info: [1788106654997] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:34 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:35 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:36 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:36 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:37 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 30 18:17:37 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:37 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:37 volumio-total go-librespot[2909]: go-librespot daemon starting... Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=debug msg="app state loaded" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02: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]" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02: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]" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02: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]" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=info msg="zeroconf server listening on port 40085" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=debug msg="obtained new client token: AAGQ9ky8y2IX2ZNLSi4ObSOtVnhb4OLWVeGJR5QzS1EFd5OMtZg2ohqZ98+ACdHENaKIPsKv70CmqeOtU3VtR6u0ZnI2dyPXGNQ3xsoUPbfn7XUS8HHzyHE/j93B2MvQbI63jOFQKV1TqHxjth+fRKj6JsJj2Z9TdWD8ix6B7fNPQHJKExcFly7ybdeIJBWmULopx94jsyng358A8MKzTXkx6HSS+AFg+2kkqKWJiNWbrAcWXyiV8dOEbw==" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02: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" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=debug msg="completed challenge" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:37 volumio-total go-librespot[2910]: time="2026-08-30T18:17:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:37 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:37 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:39 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:39 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:40 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 30 18:17:40 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:40 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:40 volumio-total go-librespot[2937]: go-librespot daemon starting... Aug 30 18:17:40 volumio-total go-librespot[2938]: time="2026-08-30T18:17:40+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:40 volumio-total go-librespot[2938]: time="2026-08-30T18:17:40+02:00" level=debug msg="app state loaded" Aug 30 18:17:40 volumio-total go-librespot[2938]: time="2026-08-30T18:17:40+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:40 volumio-total go-librespot[2938]: time="2026-08-30T18:17:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02: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]" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02: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]" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02: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]" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=info msg="zeroconf server listening on port 37913" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=debug msg="obtained new client token: AAFs/BUZYICGEtDYlSLHtS3TU7XZd4P97LP7me4n4VCeVvkxBPemy+CUDoFl7hyQ5zMOZMbF41I08dLk7s97rht0lydBPsywJGCNKx5C82xci+s3583EYtXQ+xeTMEpYB0K5HIUasjdy+eCMqZDwCt1DIkBAjeb6APHY1eYTOUKAbDMzxRo1mFllV6r0zJVlOyx4MFOAcTK2OIkTyI0xnQH2jXTSnNOmcgv/UzDtaQY9DTs3EHo4XTo=" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=debug msg="completed challenge" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:41 volumio-total go-librespot[2938]: time="2026-08-30T18:17:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:41 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:41 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:41 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:41 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::play index 6 Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:41 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:41 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:41 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:41 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:41 volumio-total volumio[1389]: info: [1788106661895] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:41 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:41 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:42 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:42 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::play index 6 Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:42 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:42 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:42 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:42 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:42 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:42 volumio-total volumio[1389]: info: [1788106662123] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:42 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:42 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:42 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:42 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:44 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 30 18:17:44 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:44 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:44 volumio-total go-librespot[2952]: go-librespot daemon starting... Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=debug msg="app state loaded" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02: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]" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02: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]" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02: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]" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=info msg="zeroconf server listening on port 45927" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=debug msg="obtained new client token: AAFcNLDoatIkNTD5pLstgbN0PSimppeoAw3kq2zLJmv53uju+nf8P0n5kxUPEL/CeGAAZv5TvWjyvothJDxo227O+bi/pV8n7PbCXJvjPnJANR2seKBr/gpebrrAfTlETi5n2TrR+EX87DWyq6/meXG2DZV76NBYShH2jWuhrF+xwFtUb/7YNB2if4YRdaOnVnu9X5dHz2BoH7cP4Re2lP2ZBd1ecQdJSl/AD0um670oqv7rgn1Jsp7pqQ==" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=debug msg="completed challenge" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:44 volumio-total go-librespot[2953]: time="2026-08-30T18:17:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:44 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:44 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:45 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:45 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:46 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:46 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:46 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:46 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:46 volumio-total volumio[1389]: info: [1788106666853] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:46 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:46 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:47 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 30 18:17:47 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:47 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:47 volumio-total go-librespot[2978]: go-librespot daemon starting... Aug 30 18:17:47 volumio-total go-librespot[2979]: time="2026-08-30T18:17:47+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:47 volumio-total go-librespot[2979]: time="2026-08-30T18:17:47+02:00" level=debug msg="app state loaded" Aug 30 18:17:47 volumio-total go-librespot[2979]: time="2026-08-30T18:17:47+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:47 volumio-total go-librespot[2979]: time="2026-08-30T18:17:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02: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]" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02: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]" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02: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]" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=info msg="zeroconf server listening on port 45011" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=debug msg="obtained new client token: AAGGmweSvH4/gaEIf5T2+Xg5r79fFud9cC2BJYZehYK8X1XZ3aL3b2MqR3OSsDW4FbJr9hsnmrkbEaNHUfzKKtXfHNED/h9OXl/KuTEYZzrM4VvrRqWx6IRdf8iGE6Nhb5rGQE4nyYiyxKzGkSGjReVGyegXtmAZBsZVItKqvm3HznD4vjLHh1e/4KELfhcwBTomXulLlnmFHsF74+VSH8mJz6IfzPJAXeaD979ejnLoPEjIpfyoplg=" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=debug msg="completed challenge" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:48 volumio-total go-librespot[2979]: time="2026-08-30T18:17:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:48 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:48 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:48 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:48 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:51 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 30 18:17:51 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:51 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:51 volumio-total go-librespot[2988]: go-librespot daemon starting... Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=debug msg="app state loaded" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:51 volumio-total volumio[1389]: info: VolumeController::SetAlsaVolume30 Aug 30 18:17:51 volumio-total volumio[1389]: info: CoreStateMachine::pushState Aug 30 18:17:51 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:51 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 18:17:51 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushState Aug 30 18:17:51 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:51 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:51 volumio-total volumio[1389]: info: peppy_screensaver: pushState - status=stop service=spop volatile=false Aug 30 18:17:51 volumio-total volumio[1389]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Aug 30 18:17:51 volumio-total volumio[1389]: SPOTIFY: SPOTIFY VOLUME 10 Aug 30 18:17:51 volumio-total volumio[1389]: SPOTIFY: VOLUMIO VOLUME 30 Aug 30 18:17:51 volumio-total volumio[1389]: SPOTIFY: DELTA VOLUME ENOUGH: true Aug 30 18:17:51 volumio-total volumio[1389]: info: Setting Spotify Volume from Volumio: 30 Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02: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]" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02: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]" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02: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]" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=info msg="zeroconf server listening on port 41513" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=debug msg="obtained new client token: AAGClmZ8ivf9ZSbJ6t/LzQqjGCFQwax1O9LqkaXwAPxaAbrIrcAbGGHdFdf2Ur2M6PNbZpF0liPj1TRXwhw7JDVJXEAVvZYqddvOuihlLhTsTT3ICCJbhZ8eoyl6kiIS+C8K5i0+xAxWF9PpXbnBU5QQzuklXO1nfr6J8dZwtnrSb8U08P1C8Tn4uhCxAJogXpSBc71f2KYjQIDmLb8nNtjtpY2ki1HaY6o27GMM43xCzvuwyClJNJB+uA==" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=debug msg="completed challenge" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:51 volumio-total go-librespot[2989]: time="2026-08-30T18:17:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:51 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:51 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:51 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:51 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:53 volumio-total volumio[1389]: SPOTIFY: SETTING SPOTIFY VOLUME 30 Aug 30 18:17:53 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/volume Aug 30 18:17:53 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:53 volumio-total volumio[1389]: info: VolumeController::SetAlsaVolume20 Aug 30 18:17:53 volumio-total volumio[1389]: info: CoreStateMachine::pushState Aug 30 18:17:53 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:53 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 18:17:53 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushState Aug 30 18:17:53 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:53 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:53 volumio-total volumio[1389]: info: peppy_screensaver: pushState - status=stop service=spop volatile=false Aug 30 18:17:53 volumio-total volumio[1389]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Aug 30 18:17:53 volumio-total volumio[1389]: SPOTIFY: SPOTIFY VOLUME 30 Aug 30 18:17:53 volumio-total volumio[1389]: SPOTIFY: VOLUMIO VOLUME 20 Aug 30 18:17:53 volumio-total volumio[1389]: SPOTIFY: DELTA VOLUME ENOUGH: true Aug 30 18:17:53 volumio-total volumio[1389]: info: Setting Spotify Volume from Volumio: 20 Aug 30 18:17:54 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:54 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:54 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 30 18:17:54 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:54 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:54 volumio-total go-librespot[3003]: go-librespot daemon starting... Aug 30 18:17:54 volumio-total go-librespot[3004]: time="2026-08-30T18:17:54+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:54 volumio-total go-librespot[3004]: time="2026-08-30T18:17:54+02:00" level=debug msg="app state loaded" Aug 30 18:17:54 volumio-total go-librespot[3004]: time="2026-08-30T18:17:54+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:54 volumio-total go-librespot[3004]: time="2026-08-30T18:17:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02: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]" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02: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]" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02: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]" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=info msg="zeroconf server listening on port 36299" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=debug msg="obtained new client token: AAG8uJoLLXCNqiN/Z7I5RtsaIm5Zuk075cuyS5oarw94vM9jVaEO6We4zoWI/WlvVsBsqzbESghPlCmhMFQCnNuNMvxLIIKNgoILyvKziCYhQjJ4/SLTh8tTFG1rC2GbJmYAR+X8huBs50/n/iRbMi0+GuV6LlCa9g0pMweN7yUODxJbiW0BhpZRoN9wX2arUl+xDmg0W1hoVIimpeKecN56ZWIPRDuRfDhkHkxfh6gvN/8wiPEypGU=" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=debug msg="completed challenge" Aug 30 18:17:55 volumio-total volumio[1389]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Aug 30 18:17:55 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/volume Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:55 volumio-total go-librespot[3004]: time="2026-08-30T18:17:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:55 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Aug 30 18:17:55 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:55 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 6 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::play index 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: [1788106676176] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:56 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:56 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::play index 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: [1788106676775] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:56 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:56 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::play index 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:17:56 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:17:56 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:56 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:17:56 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:17:56 volumio-total volumio[1389]: info: [1788106676999] ControllerSpotify::clearAddPlayTrack Aug 30 18:17:56 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:17:57 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:57 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:17:57 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:17:58 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 30 18:17:58 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:58 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:17:58 volumio-total go-librespot[3029]: go-librespot daemon starting... Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=debug msg="app state loaded" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=debug msg="stored credentials not found" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02: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]" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02: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]" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02: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]" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=info msg="zeroconf server listening on port 45437" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=debug msg="obtained new client token: AAEywlkFOY5cwbjg1rqOq5vYAmOSSWI6ROb5F+Xl8sHoyBoSXSsCxtFbKlMtWVS2B8Nzcl3md7AXtugiPo+h0F4zFdgUKXxvOIqagGoOIlmWI5AbnAHfxXHIJLYtx+l9ejORrW02Fd2cUXhQYj8qn2VWklNv+fM59TI7hFgg4nCyLLb5UEFpFkTEtCabZKdNHubP4qvkoK36nh3hUmFAoqdfTGtLVa1CoatYSRKh5tXI4YjwiOCqeI9nEA==" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=debug msg="completed keyexchange" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=debug msg="completed challenge" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:17:58 volumio-total go-librespot[3030]: time="2026-08-30T18:17:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:17:58 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:17:58 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:00 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:00 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:01 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 30 18:18:01 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:01 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:01 volumio-total go-librespot[3039]: go-librespot daemon starting... Aug 30 18:18:01 volumio-total go-librespot[3040]: time="2026-08-30T18:18:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:01 volumio-total go-librespot[3040]: time="2026-08-30T18:18:01+02:00" level=debug msg="app state loaded" Aug 30 18:18:01 volumio-total go-librespot[3040]: time="2026-08-30T18:18:01+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:01 volumio-total go-librespot[3040]: time="2026-08-30T18:18:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02: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]" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02: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]" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02: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]" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=info msg="zeroconf server listening on port 34837" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=debug msg="obtained new client token: AAH/om4Rwwa74ka7FPvHLRCTzFSqq6fLAhHbvYJVWpoyey4E+L5S6wKU3Pj1mkRMRFjgyOlHNXqVFYPJM8YtLd0T0JVffFY1/bX6FzrF4o19e5tYdqFYjdUq7U3vBi1No+kC7ZM/vcQopi6e1T62K3k2QEYunfVa9VBuPuQQREgFw+9FqfxU2H3huEV34YpeIy9ciFkKacMaSh8X0AqMy0oXBHzYQENU06Djs7lKag60LUOD6spOD+4=" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=debug msg="completed challenge" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:02 volumio-total go-librespot[3040]: time="2026-08-30T18:18:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:02 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:02 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:02 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:18:02 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::play index 4 Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:18:02 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:18:02 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:18:02 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 4 Aug 30 18:18:02 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:18:02 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 4 Aug 30 18:18:02 volumio-total volumio[1389]: info: [1788106682844] ControllerSpotify::clearAddPlayTrack Aug 30 18:18:02 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:18:02 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:03 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:03 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:05 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 30 18:18:05 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:05 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:05 volumio-total go-librespot[3049]: go-librespot daemon starting... Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=debug msg="app state loaded" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02: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]" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02: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]" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02: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]" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=info msg="zeroconf server listening on port 41323" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=debug msg="obtained new client token: AAHyIozhoMvqp0zADoE8r2Bpm6n0qY7NxV6Vu7z0BRzWRq9uL47RVjFYgaNyO25LK74BMVwOQudNaahLqYwMhZhgRGNqifcZgXq6o9X0MFhi/OThMiT+nsqzkqu9+zsplTkn2Fo2t7E35oPLn8wsdCYWBX69EG52mW9woeVh13lHOxeiwJQZEDHncwt8EXWJ8C4mqdDiDYcMXpyfhudEIov/+IZE0SBbSZ9NQG6GzKuVdw24eXP2SWdztQ==" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=debug msg="completed challenge" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:05 volumio-total go-librespot[3050]: time="2026-08-30T18:18:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:05 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:05 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:06 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 30 18:18:06 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 30 18:18:06 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:06 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:08 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 30 18:18:08 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:08 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:08 volumio-total go-librespot[3074]: go-librespot daemon starting... Aug 30 18:18:08 volumio-total go-librespot[3077]: time="2026-08-30T18:18:08+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:08 volumio-total go-librespot[3077]: time="2026-08-30T18:18:08+02:00" level=debug msg="app state loaded" Aug 30 18:18:08 volumio-total go-librespot[3077]: time="2026-08-30T18:18:08+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:08 volumio-total go-librespot[3077]: time="2026-08-30T18:18:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02: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]" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02: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]" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02: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]" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=info msg="zeroconf server listening on port 40913" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=debug msg="obtained new client token: AAGzEIDXHAQ9g5uR+SX3ABdKFyI7SLBRrW+44Hf1EDt26jmm5NkvCA4sjqy7KnSIJb92IHE75fGvVYNwXEDi3HtAXX0FeKAdSwHpzThTj6YQHTAn3eD/Et5r0CBJAsMijG1h2mSLkKvtRPSKfGso/swQnoXq1WqOP0V1N1uKQ3tkhO66zwmvYyAVO1UY7/NuUnjEvOgfzfDb1vgUwTb4M/9x3NWLX271kMlMejswVrsDmS3YEHI+aY8=" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=debug msg="completed challenge" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:09 volumio-total go-librespot[3077]: time="2026-08-30T18:18:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:09 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:09 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:09 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:09 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:10 volumio-total volumio[1389]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 30 18:18:12 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 30 18:18:12 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:12 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:12 volumio-total go-librespot[3087]: go-librespot daemon starting... Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=debug msg="app state loaded" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02: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]" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02: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]" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02: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]" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=info msg="zeroconf server listening on port 46379" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=debug msg="obtained new client token: AAE1HDuihH8n4buXSpvZL6+VuW3qIFwT5RKF2b7QXj4hentbRgIXq+G2r590ieGJwolMaDbmShnbO1KGrPs42uqp8TxAx5rdk3lp7BPA5ER+X1fpQFmkEvRvXRc5oTkrL/AUPafhZGBeShXnRDvMMN59qm8fc78pnEzCmMy9Eg4Zltqg53Cz9OgY3eCHlFIlNEjhWtuECz36zCn3s3/x8gRIAgZZo3dYSSFoYOxqD9/x/o7N3kSHYC6l7A==" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=debug msg="completed challenge" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:12 volumio-total go-librespot[3088]: time="2026-08-30T18:18:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:12 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:12 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:12 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:12 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:15 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:15 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:15 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 30 18:18:15 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:15 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:15 volumio-total go-librespot[3097]: go-librespot daemon starting... Aug 30 18:18:15 volumio-total go-librespot[3098]: time="2026-08-30T18:18:15+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:15 volumio-total go-librespot[3098]: time="2026-08-30T18:18:15+02:00" level=debug msg="app state loaded" Aug 30 18:18:15 volumio-total go-librespot[3098]: time="2026-08-30T18:18:15+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:15 volumio-total go-librespot[3098]: time="2026-08-30T18:18:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02: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]" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02: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]" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02: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]" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=info msg="zeroconf server listening on port 42997" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=debug msg="obtained new client token: AAGBBLR9a0bFRGw7di8hg+etTzGO6uxyWdj5raa4rdyVGCvWEbOisfe8Ntnqhyvh8AxzRvfbmvdLeX+iOshU5LFE2I00JxDjjOEMw05Pim6RP/mh25f5O+EqblCI2CWTkdj20EG3JUMEAp/jascXyuhd4GjSeAMZPUwkhK0+ws249zMhoJV3jfSMv2Zl/6Cj3EtpdMvUkPzjzt8pnR5ssfCG+vkTY7UV/EKOn9O6Z8qjNitnYfA7c0o=" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=debug msg="completed challenge" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:16 volumio-total go-librespot[3098]: time="2026-08-30T18:18:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:16 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:16 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:18 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:18 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:19 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 30 18:18:19 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:19 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:19 volumio-total go-librespot[3121]: go-librespot daemon starting... Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=debug msg="app state loaded" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02: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]" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02: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]" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02: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]" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=info msg="zeroconf server listening on port 37379" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=debug msg="obtained new client token: AAHPkRizRD84ZvmkasCBlkduaXdtL1CIVUMFGD/PXAJk+uNqUCBNMW/i41zleWtZtw6sgtnVytG9/ONYM14zyb/j82MC8Plcrv9vOicsqyv5+UyBzG8RPn6sjILANK2O5841w8Yxvc3sD54+2wcJpboFZ5Mm9qf1VMgS3Y7fqxSmoopq9nEFZ1hJo1bnv9kH30vkdosg4AjrrL2qDVkgbbusaOa+fB9LEPZU4GVeJH9rUFPw+pkwQzzawQ==" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=debug msg="completed challenge" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:19 volumio-total go-librespot[3122]: time="2026-08-30T18:18:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:19 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:19 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:21 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:21 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:22 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 30 18:18:22 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:22 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:22 volumio-total go-librespot[3131]: go-librespot daemon starting... Aug 30 18:18:22 volumio-total go-librespot[3132]: time="2026-08-30T18:18:22+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:22 volumio-total go-librespot[3132]: time="2026-08-30T18:18:22+02:00" level=debug msg="app state loaded" Aug 30 18:18:22 volumio-total go-librespot[3132]: time="2026-08-30T18:18:22+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:22 volumio-total go-librespot[3132]: time="2026-08-30T18:18:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02: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]" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02: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]" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02: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]" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=info msg="zeroconf server listening on port 41771" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=debug msg="obtained new client token: AAGe+YKLf8f9sq6A3plncY9RusnF0Te/YmBrofi+KtEn5Vyfny6Jm0KHrxDe1zJSkPHHsG9qnxlI2kwbFBXzLv1NhnnozUZK8Di9qyFRjXMjQX9IvnMnX5Qeb0jAQnthksCzhbGjAiKPlsaUef9yNeqrqy654Pjr95of77+qvuDqMkw72MhN0hdnZH57I0TRz4tQnisNIFM6upBKtFxA/qhyZqp2uW/q2IGB7zFKunkz+buWsI+ZSwg=" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=debug msg="completed challenge" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:23 volumio-total go-librespot[3132]: time="2026-08-30T18:18:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:23 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:23 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:24 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:24 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:26 volumio-total volumio[1389]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 30 18:18:26 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 30 18:18:26 volumio-total volumio[1389]: info: Creating Spotify config file Aug 30 18:18:26 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 18:18:26 volumio-total volumio[1389]: info: Spotify config file written Aug 30 18:18:26 volumio-total sudo[3149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 30 18:18:26 volumio-total sudo[3149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 18:18:26 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:26 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:26 volumio-total go-librespot[3151]: go-librespot daemon starting... Aug 30 18:18:26 volumio-total sudo[3149]: pam_unix(sudo:session): session closed for user root Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=debug msg="app state loaded" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02: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]" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02: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]" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02: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]" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=info msg="zeroconf server listening on port 32931" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=debug msg="obtained new client token: AAFoc7ynjoyewontt/9qtqc53TFXd0lPkpVNRxRuTqRaJ+4fcU7ehllGGotjAA65vnAtp9SuVcap4bdk1ycuIRlGr4TZLWvYi1LF4xuE2fbNc8DSZK9A6d9ZQU/lF7vO4ekog9OfKPTlaLyoBakjnIT1q6e7b3D2HyGpWFqexnCzYhgus/7J2JFXKPfvNZH4Rj6zKH9HBRRoGDoe699pup8PsgV1QofXl8xXjsOUDvuLdfq9AIPeyvleZQ==" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=debug msg="completed challenge" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:26 volumio-total go-librespot[3152]: time="2026-08-30T18:18:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:26 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:26 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:27 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:27 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:29 volumio-total volumio[1389]: info: go-librespot daemon successfully initialized Aug 30 18:18:29 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 30 18:18:29 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:29 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:29 volumio-total go-librespot[3176]: go-librespot daemon starting... Aug 30 18:18:29 volumio-total go-librespot[3177]: time="2026-08-30T18:18:29+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:29 volumio-total go-librespot[3177]: time="2026-08-30T18:18:29+02:00" level=debug msg="app state loaded" Aug 30 18:18:29 volumio-total go-librespot[3177]: time="2026-08-30T18:18:29+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:29 volumio-total go-librespot[3177]: time="2026-08-30T18:18:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02: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]" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02: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]" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02: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]" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=info msg="zeroconf server listening on port 43089" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=debug msg="obtained new client token: AAHnI05uERR0P86yNR6csnlHMe94U5LtcqtXUJp04zHVaNznhiBSd0S/ZiqJQKnvumL1Ln52Vnlo/vKEtkpKAeTMT8aVeN8GNDU2Jw/pfpMvn5SCtQ7ZztOHT4XQIxzvjv7uWf0LsOSRjXmf4FWi6eUfxEn7SwIe0ea7YzPGGJgEE+HPkwjRwGVdT6/4bfw+oGPkyx8UYBEVCJ+QFrM86nuRptQfykpcFtJanvO4RwG6rWBncxsfpnU=" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=debug msg="completed challenge" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:30 volumio-total go-librespot[3177]: time="2026-08-30T18:18:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:30 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:30 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:30 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:30 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:31 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:18:31 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 4 Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::play index 5 Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:18:31 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:18:31 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:18:31 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:31 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:18:31 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:31 volumio-total volumio[1389]: info: [1788106711617] ControllerSpotify::clearAddPlayTrack Aug 30 18:18:31 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:18:31 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:32 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:32 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:33 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Aug 30 18:18:33 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:33 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:33 volumio-total go-librespot[3186]: go-librespot daemon starting... Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=debug msg="app state loaded" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02: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]" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02: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]" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02: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]" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=info msg="zeroconf server listening on port 43923" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=debug msg="obtained new client token: AAHaq+bgZvN7Cc7QLz3raLOM8Ysgqxs0luOpclau9v7piA7O/A0P5c6SByid4Ps29dTHSNcx3Bkf641rEe8XBBEZPGRYR4yZ8lR9ZpO8LKaPNyGBAEbYoXX1sqElmfS07+YpxVaij3OBxU7ixu/gkGI0qFoGgR8V2JxoEFcn/C2IckS9GPf4xKOouiJQH35M2WySEAYpIryc8sANKQk+2n8az2O8dx6gqIHJ8HfLci/qbf/NJLvOAgFv9w==" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02: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" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=debug msg="completed challenge" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:33 volumio-total go-librespot[3187]: time="2026-08-30T18:18:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:33 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:33 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:35 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:35 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:36 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 30 18:18:36 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:36 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:36 volumio-total go-librespot[3196]: go-librespot daemon starting... Aug 30 18:18:36 volumio-total go-librespot[3197]: time="2026-08-30T18:18:36+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:36 volumio-total go-librespot[3197]: time="2026-08-30T18:18:36+02:00" level=debug msg="app state loaded" Aug 30 18:18:36 volumio-total go-librespot[3197]: time="2026-08-30T18:18:36+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:36 volumio-total go-librespot[3197]: time="2026-08-30T18:18:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02: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]" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02: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]" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02: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]" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=info msg="zeroconf server listening on port 43901" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=debug msg="obtained new client token: AAG0WyqxWQTIkj83846mPOkYhvgd7Oo5UjuZmz3NfevOx3Tje7PlD/jfV/WZt7mgBx0OuQst2gBjyQE4flwPTUBemWV0eFAnFmGxcvckQMuJG1iMZ1qb87YDODe/32UOkOGmvNLmvpxq4JR/JU2bIID4/UYTacfvLvIwPUrKWpjMDvU94232/RcCnQ5tRoq9zLaN9YJw0ja3/nqx1j0NLtc3WMe5NN6O7+tLkiD0FjK8WDxd9e5rVaE=" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=debug msg="completed challenge" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:37 volumio-total go-librespot[3197]: time="2026-08-30T18:18:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:37 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:37 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:38 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:38 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:38 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:18:38 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:38 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:18:38 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:18:38 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:18:38 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:38 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:38 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:18:38 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:38 volumio-total volumio[1389]: info: [1788106718383] ControllerSpotify::clearAddPlayTrack Aug 30 18:18:38 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:18:38 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:40 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Aug 30 18:18:40 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:40 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:40 volumio-total go-librespot[3222]: go-librespot daemon starting... Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=debug msg="app state loaded" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02: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]" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02: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]" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02: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]" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=info msg="zeroconf server listening on port 35129" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=debug msg="obtained new client token: AAFQNv++VCH/SDhfrq7EhteEmf7pLno7L3DUQCXEjao6w8qJPDsMhV3f+h70nLmNd8rsmy4U7GldnbDNi4jfXZaFUdrktAgVwVnpOY/+HNJAoVDloBxcLzX4Y0Jp0JYXT9KS8Aws+22xFqamHiMmwgFhdbiTP7aeWIEi6+zapcx9fHvnKz3ILCn5OWtmieb3HHLHN6Bf2IZmFOwvH/5jNeE9DuTGRPBaefaVMYNoe7H5RRzHOCN8BSCYWA==" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=debug msg="completed challenge" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:40 volumio-total go-librespot[3223]: time="2026-08-30T18:18:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:40 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:40 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:41 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:41 volumio-total volumio[1389]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioSeek Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreStateMachine::seek Aug 30 18:18:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:41 volumio-total volumio[1389]: info: TRACKBLOCK {"uri":"spotify:track:6BZD6qRbi1MfwBtFOTvDCh","service":"spop","name":"Euphoria - Live In Concertgebouw","artist":"Emma Kok","album":"Live In Concertgebouw","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b27330fcca80cb2331947ec6dc8f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"} Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:18:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:41 volumio-total volumio[1389]: info: Spotify seek to: 10000 Aug 30 18:18:41 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/seek Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreStateMachine::pushState Aug 30 18:18:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushState Aug 30 18:18:41 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:18:41 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:41 volumio-total volumio[1389]: info: peppy_screensaver: pushState - status=stop service=spop volatile=false Aug 30 18:18:41 volumio-total volumio[1389]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Aug 30 18:18:41 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/seek: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:43 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:18:43 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:43 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:18:43 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:18:43 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:18:43 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:43 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:43 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:18:43 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:43 volumio-total volumio[1389]: info: [1788106723760] ControllerSpotify::clearAddPlayTrack Aug 30 18:18:43 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:18:43 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:43 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Aug 30 18:18:43 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:43 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:43 volumio-total go-librespot[3232]: go-librespot daemon starting... Aug 30 18:18:43 volumio-total go-librespot[3233]: time="2026-08-30T18:18:43+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:43 volumio-total go-librespot[3233]: time="2026-08-30T18:18:43+02:00" level=debug msg="app state loaded" Aug 30 18:18:43 volumio-total go-librespot[3233]: time="2026-08-30T18:18:43+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:43 volumio-total go-librespot[3233]: time="2026-08-30T18:18:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02: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]" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02: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]" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02: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]" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=info msg="zeroconf server listening on port 38207" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=debug msg="obtained new client token: AAEG8FP7dB2wiUGtyNTV0zWhidze57pJrK9uX+AB/mN8lZQpV/Q5aJ0ovYcyaIrZfQVjmxU+TqGvsXCdJRhrP7gq9cGmGy7U1ZQ0OucrXmF113KZVKPN1m9KaZi2vUK+bZ7+LlovYNkO6z/FOnynmSx0IkdJN8Yg0vEpF5wEO2wlJL6XtQU6bLHeN/2cgMjjWMnHarE1Y2hopPfYcpQVFdSh+SdHKa4dFlrh1cJUnNOnDHauVMNp3OI=" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=debug msg="completed keyexchange" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=debug msg="completed challenge" Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=info msg="authenticated AP" username="31************************im" Aug 30 18:18:44 volumio-total volumio[1389]: info: Initializing connection to go-librespot Websocket Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=debug msg="new websocket client" Aug 30 18:18:44 volumio-total volumio[1389]: info: Connection to go-librespot Websocket established Aug 30 18:18:44 volumio-total go-librespot[3233]: time="2026-08-30T18:18:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 30 18:18:44 volumio-total volumio[1389]: info: Connection to go-librespot Websocket closed Aug 30 18:18:44 volumio-total systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 30 18:18:44 volumio-total systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 30 18:18:46 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::ClearQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::clearPlayQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:18:46 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7CByuZeDV4syW8O8hPVAnF Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioGetState Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 5 Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPlay Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::play index 0 Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::addQueueItems Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::addQueueItems Aug 30 18:18:46 volumio-total volumio[1389]: info: Preload queue cleared Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3l2YonZos6mqb4u2rwk2zr Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3bMs6bUPpeRgXY5tDmNXZU Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:4yozol821zh2HhcIPiFuTV Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:2AG5zv50AkMMct4nZk9q2k Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:6BZD6qRbi1MfwBtFOTvDCh Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:7tostJTMXhaRiVLTTXcvhe Aug 30 18:18:46 volumio-total volumio[1389]: info: Adding Item to queue: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:18:46 volumio-total volumio[1389]: info: Using cached record of: spotify:track:3DwQ7AH3xGD9h65ezslm6q Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::stop Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreCommandRouter::volumioPushQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::saveQueue Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::play index undefined Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::updateTrackBlock Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrackBlock Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 0 Aug 30 18:18:46 volumio-total volumio[1389]: info: CoreStateMachine::startPlaybackTimer Aug 30 18:18:46 volumio-total volumio[1389]: info: CorePlayQueue::getTrack 0 Aug 30 18:18:46 volumio-total volumio[1389]: info: [1788106726229] ControllerSpotify::clearAddPlayTrack Aug 30 18:18:46 volumio-total volumio[1389]: info: Sending Spotify command with payload to local API: /player/play Aug 30 18:18:46 volumio-total volumio[1389]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:47 volumio-total volumio[1389]: info: Getting Spotify volume Aug 30 18:18:47 volumio-total volumio[1389]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 18:18:47 volumio-total volumio[1389]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 30 18:18:47 volumio-total volumio[1389]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 30 18:18:47 volumio-total volumio[1389]: errno: -111, Aug 30 18:18:47 volumio-total volumio[1389]: code: 'ECONNREFUSED', Aug 30 18:18:47 volumio-total volumio[1389]: syscall: 'connect', Aug 30 18:18:47 volumio-total volumio[1389]: address: '127.0.0.1', Aug 30 18:18:47 volumio-total volumio[1389]: port: 9879, Aug 30 18:18:47 volumio-total volumio[1389]: response: undefined Aug 30 18:18:47 volumio-total volumio[1389]: } Aug 30 18:18:47 volumio-total volumio[1389]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 18:18:47 volumio-total systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Aug 30 18:18:47 volumio-total systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:47 volumio-total systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 30 18:18:47 volumio-total go-librespot[3254]: go-librespot daemon starting... Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02:00" level=info msg="running go-librespot 0.7.1" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02:00" level=debug msg="app state loaded" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02:00" level=debug msg="stored credentials not found" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 30 18:18:47 volumio-total sudo[3265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 18:17' Aug 30 18:18:47 volumio-total sudo[3265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02: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]" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02: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]" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02: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]" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02:00" level=info msg="zeroconf server listening on port 41241" Aug 30 18:18:47 volumio-total go-librespot[3255]: time="2026-08-30T18:18:47+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"