-- Logs begin at Fri 2025-12-12 06:10:32 MST, end at Fri 2025-12-12 08:49:50 MST. -- Dec 12 08:48:00 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:00 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379586. Dec 12 08:48:00 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:00 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: go-librespot daemon starting... Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=debug msg="app state loaded" Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:00 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138:3000 from 192.168.4.206 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 12 08:48:00 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138:3000 from 192.168.4.206 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=info msg="zeroconf server listening on port 38447" Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:00 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:00-07:00" level=debug msg="new websocket client" Dec 12 08:48:00 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket established Dec 12 08:48:01 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:01-07:00" level=debug msg="obtained new client token: AAByd0VS/JFifKajtlH/YCankd3EYfG1je15SJ3VaSPzSHc41XnZD9XlWUTwWHOwVRGVbAv/220JrLzDJZm9UflnQvDmla2UHk2ooW6FHYVbkpJthchdKzeN1quk4sbR+u9VA0LY+kmFr3GHW9cqhp1C8at/TF55nMc1f137Y44Lfevw+2yA35vITJijtda/mV1t+tmF5Vbj+Ij2qSsQt4uy+yW3Ai+QlAXDW24Tio1Q6wXS2rYVAGUwodJm" Dec 12 08:48:01 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:01-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:01 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:01-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:01 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:01-07:00" level=debug msg="completed challenge" Dec 12 08:48:01 kirwan-rivo go-librespot[5971]: time="2025-12-12T08:48:01-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:01 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:01 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:01 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket closed Dec 12 08:48:03 kirwan-rivo volumio[3285]: info: Getting Spotify volume Dec 12 08:48:03 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:03 kirwan-rivo volumio[3285]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Dec 12 08:48:03 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 40964) Dec 12 08:48:03 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 12 08:48:04 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:04 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Dec 12 08:48:04 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 33 Dec 12 08:48:04 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 32 Dec 12 08:48:04 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 12 08:48:04 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:04 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:04 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:04 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379587. Dec 12 08:48:04 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:04 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: go-librespot daemon starting... Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=debug msg="app state loaded" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=info msg="zeroconf server listening on port 42793" Dec 12 08:48:04 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:04-07:00" level=debug msg="obtained new client token: AACIcbqG2wguyFnhKJfyQ54OuivQnQITSaen9a4Jt2QZKjvPvU0Xq62JM9Fk02QodPpzbAUHhQTpBpbihhSOjgIakqM6PuYJRwt16SJZJLnp+4FbGTbq7/yl7IozzrkT95CKq2pU06qX4ylLkrJUuWQEQZ42DPqw9lSjVpkgNM6Ai4djTIWKMnkrCIYdGRhBDhoIk6m+BfrLkWxDs9c3nM7WfY1/zW+ZZUL5j12+On995bnsswmh+piyHXFg" Dec 12 08:48:05 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:05-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:05 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:05-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:05 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:05-07:00" level=debug msg="completed challenge" Dec 12 08:48:05 kirwan-rivo go-librespot[5992]: time="2025-12-12T08:48:05-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:05 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:05 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:06 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138:3000 from 192.168.4.206 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:06 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138:3000 from 192.168.4.206 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 12 08:48:06 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 12 08:48:07 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:07 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:08 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:08 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379588. Dec 12 08:48:08 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:08 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: go-librespot daemon starting... Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="app state loaded" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=info msg="zeroconf server listening on port 33007" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="obtained new client token: AABi6V5YdMmqVIg2jQ7pDacPhKLB4u91KImu0YSPIZOHevMRpdHYUf8j0Af9Jp/a9fYav/pNRCHKNH8fDIibNNmpWekNIjxSAbjfyvMZHrFwx0Sy5hLA7huDfyz6zdqzQ/Q1uKk8O8yK3t3jcIyeWi0He0SkM/kJZqPefD71zZRNtuVEIQkxX/V7sHL/3BwJiO7o2ZY5KGSmyxtF2rAtJfMqqolAhFnpVjBVqegsqCk40y+12SAhufBEYd+s" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:08 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:08-07:00" level=debug msg="completed challenge" Dec 12 08:48:09 kirwan-rivo go-librespot[6017]: time="2025-12-12T08:48:09-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:09 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:09 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:10 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:10 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:12 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:12 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379589. Dec 12 08:48:12 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:12 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: go-librespot daemon starting... Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="app state loaded" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:12 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138:3000 from 192.168.4.206 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 12 08:48:12 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=info msg="zeroconf server listening on port 34861" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="obtained new client token: AACxc6gP6gnAPB6ULh1wvuumP9R4/SDSsJErOb0LRg64mb0igIhvRiiusxLqMdP990qtjMKIbAfgQXkjQ2x9vTJ5pygx21+HGiemve11djDDBY6uEKwFDnBWaTR2g38A0Fopp54DhUONypDZu92rA3zgaL4e2CtyKd/MdJECBw2ymlllok8/CDEzI6Pa3iqfELWjgL4RSef0l13/pk8QzDDAa2DywSSZEdVAj9CXr49lA6+sjHPeZ6Gnh0wc" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=debug msg="completed challenge" Dec 12 08:48:12 kirwan-rivo go-librespot[6037]: time="2025-12-12T08:48:12-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:12 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:12 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:13 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:13 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:15 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:15 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379590. Dec 12 08:48:15 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:15 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: go-librespot daemon starting... Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="app state loaded" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=info msg="zeroconf server listening on port 38613" Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="new websocket client" Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket established Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="obtained new client token: AADzmdoOXRyRfu0g9WvACoz5/NsWXPv8cb3wJqqanjvlNEA1Yc3IbMX5J7fnK2gMKgExuBL64Q9+CTu+oNHlQxWl/9hiUGlx8fdrgKIOmUyQQI9beikA0c+3KxAvkUzGqAeHyCMP8JPgt6akw2K+c5ZeCZWGEocmMsS7McSxt/SSe2bvIEKHSOTgDZApQUX7oTfu+sMYhMljUmAiaH1xsgq6eX4msrld4icXpkoeHmjxyTgBQYEhI9XNzYq4" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="connected to ap-guc3.spotify.com:443" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=debug msg="completed challenge" Dec 12 08:48:16 kirwan-rivo go-librespot[6062]: time="2025-12-12T08:48:16-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:16 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:16 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket closed Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 12 08:48:16 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 12 08:48:16 kirwan-rivo sudo[6071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 12 08:48:16 kirwan-rivo sudo[6071]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:16 kirwan-rivo sudo[6071]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:16 kirwan-rivo sudo[6077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 12 08:48:17 kirwan-rivo sudo[6077]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:17 kirwan-rivo sudo[6077]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:17 kirwan-rivo sudo[6085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 12 08:48:17 kirwan-rivo sudo[6085]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:17 kirwan-rivo sudo[6085]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:17 kirwan-rivo sudo[6092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 12 08:48:17 kirwan-rivo sudo[6092]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:17 kirwan-rivo sudo[6092]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:17 kirwan-rivo sudo[6099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 08:48:17 kirwan-rivo sudo[6099]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:17 kirwan-rivo sudo[6099]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:17 kirwan-rivo sudo[6103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 08:48:17 kirwan-rivo sudo[6103]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:17 kirwan-rivo sudo[6103]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 12 08:48:17 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 12 08:48:17 kirwan-rivo volumiologrotate[2832]: ls: cannot access '/var/log/samba/log.wb-KIRWAN': No such file or directory Dec 12 08:48:17 kirwan-rivo volumiologrotate[2832]: ls: cannot access 'RIVO': No such file or directory Dec 12 08:48:18 kirwan-rivo sudo[6151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 08:48:18 kirwan-rivo sudo[6151]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:18 kirwan-rivo sudo[6151]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:18 kirwan-rivo sudo[6155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 08:48:18 kirwan-rivo sudo[6155]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:18 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138:3000 from 192.168.4.206 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Dec 12 08:48:18 kirwan-rivo sudo[6155]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 12 08:48:18 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138 from 192.168.4.206 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetVisibleSources Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:18 kirwan-rivo sudo[6159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 08:48:18 kirwan-rivo sudo[6159]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:18 kirwan-rivo sudo[6159]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:18 kirwan-rivo sudo[6163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 08:48:18 kirwan-rivo sudo[6163]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:18 kirwan-rivo sudo[6163]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:18 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to 192.168.4.138 from 192.168.4.206 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: Listing playlists Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 12 08:48:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 12 08:48:19 kirwan-rivo volumio[3285]: info: Getting Spotify volume Dec 12 08:48:19 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:19 kirwan-rivo volumio[3285]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Dec 12 08:48:19 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 40965) Dec 12 08:48:19 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 12 08:48:19 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:19 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Dec 12 08:48:19 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 33 Dec 12 08:48:19 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 32 Dec 12 08:48:19 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 12 08:48:19 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:19 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:19 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:19 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379591. Dec 12 08:48:19 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:19 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: go-librespot daemon starting... Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="app state loaded" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=info msg="zeroconf server listening on port 37551" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="obtained new client token: AACAmJa0OC5pNDyU9HtwT6XW9uWUbFjFU3Jyz+oUyPHtQT/oNtN0OhvMwRwG2CV13mopKWSyW8sAWSDxRK083ifatGrWwj/pilAxQkS4MCWqS+Nm/hUKjVZMVXz9tUeqCdHit0IXmwbyT4WWiwdCxZxwS2StsFIny21w23cV8KReyJ2VLQuCRxUgL18qreqpcS1BTY8yhFhzvKaNRtPtoHMAEVP/fcbUc9Bz32HJfAVpAxxjGBmwEWxsLizO" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=debug msg="completed challenge" Dec 12 08:48:20 kirwan-rivo go-librespot[6166]: time="2025-12-12T08:48:20-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:20 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:20 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:22 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:22 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:23 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:23 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379592. Dec 12 08:48:23 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:23 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: go-librespot daemon starting... Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="app state loaded" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=info msg="zeroconf server listening on port 44893" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="obtained new client token: AACeBcZ/Cxc1Pny4njiQfJbtTuEK1NB38SQ6XlWdh+QHct+6gbPhIkwJ88PaSdolXXSm0vacJVgANsELo/0KuQRePrxKmpT6orv8DtDDF/rBOqJz0Xi8Qq1L9iw6M7LefvFs/a/own3J/yuGAh3ACfAeJlGgGuPt0ywvY2h9LaBJ1Kc18EYS1XKM3NMP8v4Yzw9OTI9iTHeSlstkSj8TDRnNwI1Rz+qgVdVbatBK44+dVZTVjFj0LHj7s8uy" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=debug msg="completed challenge" Dec 12 08:48:24 kirwan-rivo go-librespot[6177]: time="2025-12-12T08:48:24-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:24 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:24 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:25 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:25 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:27 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:27 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379593. Dec 12 08:48:27 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:27 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:27 kirwan-rivo go-librespot[6214]: go-librespot daemon starting... Dec 12 08:48:27 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:27-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:27 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:27-07:00" level=debug msg="app state loaded" Dec 12 08:48:27 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:27-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:27 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:27-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=info msg="zeroconf server listening on port 43275" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="obtained new client token: AAATSe6yLyb0FxbAdx3GmV+ZNrFWbPCdv7tORCEjdv4av1kP22j07do9l2Dl2BJlBjKam/qglTQfsmCQO4bBNB35l59dexiTTfhEYYtrdWUY1zZb3AvATVhoS3JwyhXaft8Fc1P+hyLzWIe2tK64TMEEL6nvxd4cUlWrX/QCSYCY5v0veTINfcodEc82YyR20XUG9A9KwQ0K/5CGXAj+5YHUU2pJN7zuRhlWAbKxwEfEiqkdNTtYdKSHXw==" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=debug msg="completed challenge" Dec 12 08:48:28 kirwan-rivo go-librespot[6214]: time="2025-12-12T08:48:28-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:28 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:28 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:28 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:28 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:31 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:31 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379594. Dec 12 08:48:31 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:31 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: go-librespot daemon starting... Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=debug msg="app state loaded" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:31 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:31 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket established Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=debug msg="new websocket client" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 12 08:48:31 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:31-07:00" level=info msg="zeroconf server listening on port 39687" Dec 12 08:48:31 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetQueue Dec 12 08:48:31 kirwan-rivo volumio[3285]: info: CoreStateMachine::getQueue Dec 12 08:48:31 kirwan-rivo volumio[3285]: info: CorePlayQueue::getQueue Dec 12 08:48:32 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:32-07:00" level=debug msg="obtained new client token: AAAn4allVAkpPwHnSQ9j/QJAKZZUi56bvHRuUKUn+k/+hcxOx8HbNe3Nb+KL7p4bnMCY4RD4Oyl9VoCmup3IKziMAnRNP811yx8u222rM9yboIV6+gVY059Pdq179OyiE2XH4gFUCr+WHjYUukVx4lrrJ8fUHWhP9XjCL5uCeqlak4UJEh627Ci9VWbms0L2k1UOFUI4+9t3iYnAqfwNCRn5EzmHsvSUllYnTzhs8+ogrmcuwWq+fEZD9rIP" Dec 12 08:48:32 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:32-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:32 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:32-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:32 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:32-07:00" level=debug msg="completed challenge" Dec 12 08:48:32 kirwan-rivo go-librespot[6223]: time="2025-12-12T08:48:32-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:32 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:32 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:32 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket closed Dec 12 08:48:34 kirwan-rivo volumio[3285]: info: Getting Spotify volume Dec 12 08:48:34 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:34 kirwan-rivo volumio[3285]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Dec 12 08:48:34 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 40966) Dec 12 08:48:34 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 12 08:48:34 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:34 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Dec 12 08:48:34 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 33 Dec 12 08:48:34 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 32 Dec 12 08:48:34 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 12 08:48:35 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:35 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:35 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:35 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379595. Dec 12 08:48:35 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:35 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: go-librespot daemon starting... Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="app state loaded" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=info msg="zeroconf server listening on port 36171" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="obtained new client token: AAAy/i4VzF3fRwhXFRTReFcWGtjQqaOtCoONqOV3IgHVhO8BNHzjsrJAm9xtxwzU/v8sP3511kuKUNpIeWI0GylkClkwN8oorez4Djd9kCdiScV75Ara5H63NVtL401MxqzI5rHF0Xxlfancv+KAzNdgLfW5155sIuyI3A4hZzbw3UbwUATmOk415UaikFWTraeudeiYVYdA326Azq2fis4knmt8PlznCsmNXc0rwxQK/p9JDwyEAeYmRS+e" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=debug msg="completed challenge" Dec 12 08:48:35 kirwan-rivo go-librespot[6249]: time="2025-12-12T08:48:35-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:35 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:35 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: Received Get System Version Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: Received Get System Info Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: Discovery: Getting this device information Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:37 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:48:38 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:38 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:38 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:38 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379596. Dec 12 08:48:38 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:38 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: go-librespot daemon starting... Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="app state loaded" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=info msg="zeroconf server listening on port 37383" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="obtained new client token: AAAtmf0lNjx7tpyvS0daePfHMBFEytMUMt/mT7Tf+a5mDqoh3f7u5UJcyvDD+hFA7wZcz1bxvY+TVozHmP02m38TvsXGxjkF7u8w7p/PMLaw5LQLET95RGLs2KhTVbgObegdw2rZ8jQJJtz5A2wbR+zzxTAJ6BpZWUmlwWqwD3O9ooLNFm/ojYAbUMdey2pNf7D3hyyZg2XQRtLKNX4dv594hGU7CGQXASvPKyuM3vCpbk20GpyNvG5xRKCT" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=debug msg="completed challenge" Dec 12 08:48:39 kirwan-rivo go-librespot[6257]: time="2025-12-12T08:48:39-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:39 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:39 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:40 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:48:40 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:48:40 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:48:40 kirwan-rivo vtcs[3940]: [2025-12-12 08:48:40.059] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:48:41 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:41 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:42 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:42 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379597. Dec 12 08:48:42 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:42 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:42 kirwan-rivo go-librespot[6266]: go-librespot daemon starting... Dec 12 08:48:42 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:42-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:42 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:42-07:00" level=debug msg="app state loaded" Dec 12 08:48:42 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:42-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:42 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:42-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=info msg="zeroconf server listening on port 34111" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="obtained new client token: AABnCyQkcmB7OTu2HWdreS74EvNb11Zjt7UfCZAEUmi0K1401ttpo80tUC+Ff0hCQ96r2By+YEazdZEJo4GHJMzjdBMYI+8AvNgav3dNoEpdl9/N5jN+Na+CIYBDk5dFmsg/j1x/sKDBaiOUL2uoqPU21vNoUQLCxs0Xrhy4nGUzKmhUG5cBLUf6vLx2F8ZjfplZZXAycYej5jpnVQ65BI4RjTc/8DEeSyEZ+9hq4OzKDlUMW1HXu5HGcA==" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=debug msg="completed challenge" Dec 12 08:48:43 kirwan-rivo go-librespot[6266]: time="2025-12-12T08:48:43-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:43 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:43 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:44 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:44 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:46 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:46 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379598. Dec 12 08:48:46 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:46 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: go-librespot daemon starting... Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=debug msg="app state loaded" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:48:46 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:46-07:00" level=info msg="zeroconf server listening on port 44833" Dec 12 08:48:47 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:47-07:00" level=debug msg="obtained new client token: AACHfIS6O1uXVx+5D0CSkjMJ3JcMG7UaTywrCXDRDVR22JWqerr5j9Q/3mStzoJWUiccrbCFaXuTilyFZ8xplUb9xDJYLmKkbmYebmm/Bqa8n2FWMgkyq1xDslCLkJVy3lRxnRWgQLO1i/WE/abDNbVJ2QoVxazyyyVZ4rNCzPTVhSQSKBBhBz47hxCFZke4/W5Wglzlv4DF7aU0SEfq+0naK+dSCuQeYOWmWomwdMETh1lNmcRPjIvQljmN" Dec 12 08:48:47 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:47-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:47 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:47-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:47 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:47-07:00" level=debug msg="completed challenge" Dec 12 08:48:47 kirwan-rivo go-librespot[6295]: time="2025-12-12T08:48:47-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:47 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:47 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:47 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:47 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:50 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:50 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:50 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:50 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379599. Dec 12 08:48:50 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:50 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: go-librespot daemon starting... Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="app state loaded" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=info msg="zeroconf server listening on port 39531" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="obtained new client token: AABOieWapGKwQk7GCISM6hyg/E5NX6NYHiBt/3attxUVB51a2A8+bOpC8H+ypxhStMSr5EG/hWD8UbAfBZl5Tx5acogrlAlZfWl1BoAWhYtfttwSYwy8nVdYgXHrvA8f4+jIz0H2QR0EUC2hKGo78C9/dfn3ubzekCWrbNVhpAmLzwym7u3U5UDD9kry1Qe4vHXpLfNYHfPcFSHNhwCrYdcwv78drWUrGD6Q7nIslObJdkAQqSSzWqi1yjDH" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=debug msg="completed challenge" Dec 12 08:48:50 kirwan-rivo go-librespot[6304]: time="2025-12-12T08:48:50-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:50 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:50 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:53 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:53 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:53 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:53 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379600. Dec 12 08:48:53 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:53 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: go-librespot daemon starting... Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="app state loaded" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: VolumeController::SetAlsaVolume42 Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: CoreStateMachine::pushState Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioPushState Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: Exiting sleep status due to volume change Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42 Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 33 Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 42 Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: Setting Spotify Volume from Volumio: 42 Dec 12 08:48:54 kirwan-rivo volumio[3285]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Dec 12 08:48:54 kirwan-rivo volumio[3285]: xcb_connection_has_error() returned true Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: MCU Signalled Sleep Mode Disabled Dec 12 08:48:54 kirwan-rivo sudo[6323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Dec 12 08:48:54 kirwan-rivo sudo[6323]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:54 kirwan-rivo kernel: fb: osd[0] enable: 1 (Xorg) Dec 12 08:48:54 kirwan-rivo kernel: fb: osd[0] enable: 1 (Xorg) Dec 12 08:48:54 kirwan-rivo sudo[6323]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:54 kirwan-rivo sudo[6327]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Dec 12 08:48:54 kirwan-rivo sudo[6327]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 12 08:48:54 kirwan-rivo sudo[6327]: pam_unix(sudo:session): session closed for user root Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: VolumeController::SetAlsaVolume46 Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: CoreStateMachine::pushState Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioPushState Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=info msg="zeroconf server listening on port 42961" Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 42 Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 46 Dec 12 08:48:54 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 12 08:48:54 kirwan-rivo volumio[3285]: info: Setting Spotify Volume from Volumio: 46 Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="obtained new client token: AACuYg5WWj2X2COPUlW2heJ5f+7JZJoNDKto2gi5mmOPQLF5XB1BoKbzN5PuU0X0Ck1i9jW9lz+dKgDYIhM1eAZTMf5pHDOyNTkRuBX8jk2i0RqqqIsR4Prq2Oawzc/k/6CbJykWLpmUuwWOPBtZV8KsBFZDHvOVMDLijmcxJeOXeS+hpp5G0HxcgdBrQRA0fArAw0Ms4q5Vkw2Ow3LARAoxZp77UOGJhYNumgO+/NHhCFqvzmLletBvo/vi" Dec 12 08:48:54 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:54-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:48:55 kirwan-rivo volumio[3285]: info: VolumeController::SetAlsaVolume51 Dec 12 08:48:55 kirwan-rivo volumio[3285]: info: CoreStateMachine::pushState Dec 12 08:48:55 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:48:55 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioPushState Dec 12 08:48:55 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Dec 12 08:48:55 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 46 Dec 12 08:48:55 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 51 Dec 12 08:48:55 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 12 08:48:55 kirwan-rivo volumio[3285]: info: Setting Spotify Volume from Volumio: 51 Dec 12 08:48:56 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:56 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:56-07:00" level=debug msg="new websocket client" Dec 12 08:48:56 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket established Dec 12 08:48:56 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:56-07:00" level=debug msg="completed keyexchange" Dec 12 08:48:56 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:56-07:00" level=debug msg="completed challenge" Dec 12 08:48:56 kirwan-rivo volumio[3285]: SPOTIFY: SETTING SPOTIFY VOLUME 51 Dec 12 08:48:56 kirwan-rivo volumio[3285]: info: Sending Spotify command with payload to local API: /player/volume Dec 12 08:48:56 kirwan-rivo go-librespot[6314]: time="2025-12-12T08:48:56-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:48:56 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:48:56 kirwan-rivo volumio[3285]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 12 08:48:56 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:48:56 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket closed Dec 12 08:48:58 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:48:58 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:48:58 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:48:58 kirwan-rivo vtcs[3940]: [2025-12-12 08:48:58.386] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: Getting Spotify volume Dec 12 08:48:59 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:59 kirwan-rivo volumio[3285]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Dec 12 08:48:59 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 40967) Dec 12 08:48:59 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:48:59 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:48:59 kirwan-rivo vtcs[3940]: [2025-12-12 08:48:59.602] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:48:59 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:48:59 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:48:59 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379601. Dec 12 08:48:59 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:48:59 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:48:59 kirwan-rivo go-librespot[6348]: go-librespot daemon starting... Dec 12 08:48:59 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:48:59-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:48:59 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:48:59-07:00" level=debug msg="app state loaded" Dec 12 08:48:59 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:48:59-07:00" level=debug msg="stored credentials not found" Dec 12 08:48:59 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:48:59-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=info msg="zeroconf server listening on port 43165" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="obtained new client token: AADqAlWKfqQkIxsKv9rDLkhoKlH0MuuDd8bMBQu1UsuyelinKcjJJ0l3eCqdNqo1Ybja+7wx3u3IC1uMkTm/hTaeH6aM6eIodrX/Y41C1KZVABnI40Jgg56TQANdglAGcvYH9KdmIZKW4yDw3dmfbd0cCiNhUeymqlk/6ESkq5tXhhw80fNXqN6vX8zNF31VuXaoEYMJsBfIhIeW3mwkT9VhRMm7GZ7ghB/rMfy+nVVNveGSwCFWcNd5Xw==" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=debug msg="completed challenge" Dec 12 08:49:00 kirwan-rivo go-librespot[6348]: time="2025-12-12T08:49:00-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:00 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:00 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:02 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:02 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:02 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:02 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:02 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:02 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:02.672] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:03 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:03 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379602. Dec 12 08:49:03 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:03 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: go-librespot daemon starting... Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=debug msg="app state loaded" Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:03 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:03 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:03 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:03 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:03.603] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:03 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:03-07:00" level=info msg="zeroconf server listening on port 38301" Dec 12 08:49:04 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:04-07:00" level=debug msg="obtained new client token: AACAv4hUsisvmGRJhkTL4Z6VoqaRR0WWPS/WLic6gbghb7nzx6M0jQY2gfVzlj6+I8FZVNX6NDKp3BnEfsP35gLuBfldxFk+IQVjGlvH3W31agIWTxVFYCF+t7/QbZrvg1g30IOoMEvSbnbpG2ARRpAzAMue882TmyilIuoXJTJsWxSz5wu/2OjfJkiSYNjIyDotqf5dUA+sk9iDuIjodp1HeFFAy34aYp1p9OmlKzOVVvqOXcfaAdgSVoym" Dec 12 08:49:04 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:04-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:04 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:04-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:04 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:04-07:00" level=debug msg="completed challenge" Dec 12 08:49:04 kirwan-rivo go-librespot[6356]: time="2025-12-12T08:49:04-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:04 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:04 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:04 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:04 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:04 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:04 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:04.720] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:05 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:05 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:07 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:07 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379603. Dec 12 08:49:07 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:07 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: go-librespot daemon starting... Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="app state loaded" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=info msg="zeroconf server listening on port 45255" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="obtained new client token: AADgazq2BEcX97cMWpZsWw9QytKlH8zg22OQa9HujTsBXiXVGNmrXgzk5Qh+kXjSUifoD4oXsVFPWHcHvLOBec8M05rnU6EbOMZ9bsMLABFlCyGw94s3vHLW2Vrj103q1QMnSS2Wrv4ugpmrmqLh+2np2POS/z95O4gIQoPBzyGTVSeh5Wh8bxWk0TGsuDBytbbXFVpeTl582/300xkWDOZj0+X2rtHVDKAdQZyjuUfM+DeqneIy3ArhLf4h" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=debug msg="completed challenge" Dec 12 08:49:07 kirwan-rivo go-librespot[6385]: time="2025-12-12T08:49:07-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:07 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:07 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:08 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:08 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:10 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:10 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379604. Dec 12 08:49:10 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:10 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: go-librespot daemon starting... Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="app state loaded" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: VolumeController::SetAlsaVolume55 Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: CoreStateMachine::pushState Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioPushState Dec 12 08:49:11 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 12 08:49:11 kirwan-rivo volumio[3285]: SPOTIFY: SPOTIFY VOLUME 51 Dec 12 08:49:11 kirwan-rivo volumio[3285]: SPOTIFY: VOLUMIO VOLUME 55 Dec 12 08:49:11 kirwan-rivo volumio[3285]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: Setting Spotify Volume from Volumio: 55 Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=info msg="zeroconf server listening on port 37171" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="obtained new client token: AAAvdCiP07359tLUFnmdOTDSDOuJLwnhRv7KPu9tbC2D4rYQEhf/OKzTXJy4+gtBEjHHxuxVn7sDdu/sD0lJ9m5/utQas7fQodbL9e+HM9v2cDad3GTIgcj4iKuCDwjUGb/OYjaooDiJQB9gQBYkpRkcANGtFqupSjP9H/5up1rTnFSXOHJeZn5rUzPB0cFJyF0utXz64azQSj3W5yPen+t7W5eN71Z0DuAO5wRoMf/hn4rSGH5KJJYmoIeQ" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="completed challenge" Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=debug msg="new websocket client" Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket established Dec 12 08:49:11 kirwan-rivo go-librespot[6393]: time="2025-12-12T08:49:11-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:11 kirwan-rivo volumio[3285]: info: Connection to go-librespot Websocket closed Dec 12 08:49:11 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:11 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:12 kirwan-rivo volumio[3285]: SPOTIFY: SETTING SPOTIFY VOLUME 55 Dec 12 08:49:12 kirwan-rivo volumio[3285]: info: Sending Spotify command with payload to local API: /player/volume Dec 12 08:49:12 kirwan-rivo volumio[3285]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:14 kirwan-rivo volumio[3285]: info: Getting Spotify volume Dec 12 08:49:14 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:14 kirwan-rivo volumio[3285]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Dec 12 08:49:14 kirwan-rivo volumio[3285]: (node:3285) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 40968) Dec 12 08:49:14 kirwan-rivo volumio[3285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 12 08:49:14 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioGetState Dec 12 08:49:14 kirwan-rivo volumio[3285]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 12 08:49:14 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:14 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:14 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:14 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379605. Dec 12 08:49:14 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:14 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:14 kirwan-rivo go-librespot[6404]: go-librespot daemon starting... Dec 12 08:49:14 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:14-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:14 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:14-07:00" level=debug msg="app state loaded" Dec 12 08:49:14 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:14-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:14 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:14-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=info msg="zeroconf server listening on port 42871" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="obtained new client token: AADeB34CrC+cCfhuG7fshWlezSjsgMBZ9POkxLmiAGhUw2NI4K9g50Ij7RGkUj9SuOt4ht2q4cHXncvXMjV3nUBh5uUQAhy9TfM72QGKYgwu8FeFuHBjZP/G4ZIPsPS0UF2rhA9QcHobiT6M7OSEzTiUVJfj3K0GRm2jl8Nlf+Bvq6agHXTc6z7zv2fStWJr7LiHxPIKHWqWFgKQwOb+p9Iga7EJQ9jNC1pfYrvKfxgGEWnTsMsuJ1xZXg==" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=debug msg="completed challenge" Dec 12 08:49:15 kirwan-rivo go-librespot[6404]: time="2025-12-12T08:49:15-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:15 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:15 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:17 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:17 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:18 kirwan-rivo volumiologrotate[2832]: ls: cannot access '/var/log/samba/log.wb-KIRWAN': No such file or directory Dec 12 08:49:18 kirwan-rivo volumiologrotate[2832]: ls: cannot access 'RIVO': No such file or directory Dec 12 08:49:18 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:18 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379606. Dec 12 08:49:18 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:18 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: go-librespot daemon starting... Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=debug msg="app state loaded" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:18 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:18 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:18 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:18 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:18.697] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=info msg="zeroconf server listening on port 36105" Dec 12 08:49:18 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:18-07:00" level=debug msg="obtained new client token: AACNNoDkw9K2dOeVKw3cRZTUBMyfPol4DR/KsODiqE3uKKJj6KIvoaBIsQ3MvUkkJW8VD1kkmxm+OWbhVaG1dB3tdr/Zdd9tBetA+tflAiqz8ILHAhlK/MaN7l+6UrAe81Z22wrRcJzme6JMjtLuFi8PUJYYd4CLDBtoG6IFvXEY+fRhcBliuukACfkd8z+VJLXpcTQ0k6FOgpogkwesuujOsSIORew/DZ2Za+gtXNce0eDEGE6OJxf9GG8e" Dec 12 08:49:19 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:19-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:19 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:19-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:19 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:19-07:00" level=debug msg="completed challenge" Dec 12 08:49:19 kirwan-rivo go-librespot[6483]: time="2025-12-12T08:49:19-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:19 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:19 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:20 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:20 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:22 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:22 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379607. Dec 12 08:49:22 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:22 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: go-librespot daemon starting... Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="app state loaded" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=info msg="zeroconf server listening on port 33897" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="obtained new client token: AABRYt2iJ5NdlOtUOKo7/HASe/gP39V9+3J70yK1ND/CczR20QdZCT2vPjj3qaKGCGH6ohi5ZFHLugVCghE7Yv8wE11iKbiQX6S81r/ADAHYewGVqiYRrmyVrbY/rDykOPodoQQaXQvEp8iLYfprUfag3ipb4BKj6VGVK3oqtktIRBk34m4NAAmi6O5tJfCyHwRBaDTCDTztvOBCqOu7xJ6giubUddVojCEsb52fMA/oqBhbAQ8ssDrprpGt" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=debug msg="completed challenge" Dec 12 08:49:22 kirwan-rivo go-librespot[6501]: time="2025-12-12T08:49:22-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:22 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:22 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:23 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:23 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:23 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:23 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:23.562] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:23 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:23 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:24 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:24 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:24 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:24 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:24.590] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:25 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:25 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379608. Dec 12 08:49:25 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:25 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: go-librespot daemon starting... Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="app state loaded" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:26 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:26 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:26 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:26 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:26.053] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=info msg="zeroconf server listening on port 39957" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="obtained new client token: AACcFc6vr72vLgg6b6QEDiLImgfTL1o1h0ORtXjwNgbIZvGAfxl1uNph4yFp6g0+sU7mS3GunHWxhI6d7pw8rN+7+sMCLPEPXyb33rl87msrqUePz3ZoL1I/8eGrCmK2uc1SJnz+dwTeLXEzxOegI5l9lfgc09ZaSUz5tthcG5K9u6OuUdf6Bd9OqhY8hxIMFuG9uDakjIVzrExQ37XAnGxC0+JZBCPwb1sVTxDD8RT9cU/VPsN6jqq3MjhS" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=debug msg="completed challenge" Dec 12 08:49:26 kirwan-rivo go-librespot[6529]: time="2025-12-12T08:49:26-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:26 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:26 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:26 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:26 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:27 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:27 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:27 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:27 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:27.248] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:28 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:28 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:28 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:28 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:28.684] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:29 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:29 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379609. Dec 12 08:49:29 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:29 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:29 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:29 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:29 kirwan-rivo go-librespot[6546]: go-librespot daemon starting... Dec 12 08:49:29 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:29-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:29 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:29-07:00" level=debug msg="app state loaded" Dec 12 08:49:29 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:29-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:29 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:29-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=info msg="zeroconf server listening on port 40441" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="obtained new client token: AACFvojUMUHmNzcyMah+fv07t18ntZQSWIViVieNmEomy5HGt4fKe4DBhVttijHTMM5CGtkknAyFPjOT2788KpjxO2R2RQFbrkI5usH/HUKySI5PL0XP/6uZPv0imCp4FxDGPZjMWrQQ9FaEiP/ak2raCfFSv/iBYBT+rB5bbLxQGyyt49iXqAg9oxkYipdED6tQBspGOvr7ah3B5TJ3lZD1qSEMq1AUWgpNpAlqGVl7KXw8qOweCLEvnA==" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=debug msg="completed challenge" Dec 12 08:49:30 kirwan-rivo go-librespot[6546]: time="2025-12-12T08:49:30-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:30 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:30 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:32 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:32 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:33 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:33 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379610. Dec 12 08:49:33 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:33 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: go-librespot daemon starting... Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=debug msg="app state loaded" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:33 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:33-07:00" level=info msg="zeroconf server listening on port 33017" Dec 12 08:49:34 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:34-07:00" level=debug msg="obtained new client token: AAChYCEZl5Rh+Vai4el1vQHxtoVAXwgNes43ZHu7RwAdU2JZLTZJJUHDcyYSd/qjWR4TrzMYsyKopO4HXwekOgNv2ObwcuVU9ejVt8rV9wPIWzasloX+JQPx8LrA9W7oaoPxW8OOfnZ/QD+cQ5GDLRHDjhttaWy7MVKIXH1Pq1mF0X753K/Ggxy4n73BVxfVQ5usQGYNok+Z7dc01Ehhp/caylNgz12xpTT/caVjYkokyXjyfuel5rWGQLiZ" Dec 12 08:49:34 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:34-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:34 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:34-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:34 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:34-07:00" level=debug msg="completed challenge" Dec 12 08:49:34 kirwan-rivo go-librespot[6558]: time="2025-12-12T08:49:34-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:34 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:34 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:35 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:35 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:37 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:37 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379611. Dec 12 08:49:37 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:37 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: go-librespot daemon starting... Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="app state loaded" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=info msg="zeroconf server listening on port 43509" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="obtained new client token: AAB83Z2dq52d7431wm45nusQsWKJpQz2X/xYECd/NUDcYrBrcQzhKht1Z5CIfCa2wuQYFzHqU83F0Df/oJavmUq82FxiOVy9Dom5YRLSqpwkkVnIYyAQVzqPEW4sM+oAI1UBWpMxuHvZfFM+gWNo2ZwJPt6jweRlrQu3SZzNo9NmflpcDpjS2cVCB5D1C+3iYbu55AhsRqZbSNF/w/3qiU567nrKdiJW5S8F5AYl8cSaT0TVm9LfisHddVbG" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=debug msg="completed challenge" Dec 12 08:49:37 kirwan-rivo go-librespot[6583]: time="2025-12-12T08:49:37-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:37 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:37 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:38 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:38 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:40 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:40 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379612. Dec 12 08:49:40 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:40 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: go-librespot daemon starting... Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="app state loaded" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=info msg="zeroconf server listening on port 41535" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="obtained new client token: AAAx7gYPAIJVrfwfiTu3TzYNxJACMAMXJPEsRq5OFG5JtQmF1pKW2/dhN9KvKyt5j5jXmh9Go3orYtJsYd/W1nFFDrneMl8lChEqCTQEqUKES9zlbcaH77yaIuCGa4bFG41lyS4DnGZgzs+3eWV+lw38R5O17b3jmUeeTiuaVRnYfhFytC5z+tZDBKfjYW11D00e3Y+49zWAm3gkdeK9HukN48A28ma/J4PTizZ8kbZPpf9ZhPg+C7/U0ezE" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=debug msg="completed challenge" Dec 12 08:49:41 kirwan-rivo go-librespot[6592]: time="2025-12-12T08:49:41-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:41 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:41 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:41 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:41 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:44 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:44 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379613. Dec 12 08:49:44 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:44 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:44 kirwan-rivo go-librespot[6611]: go-librespot daemon starting... Dec 12 08:49:44 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:44 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:44 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:44-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:44 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:44-07:00" level=debug msg="app state loaded" Dec 12 08:49:44 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:44-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:44 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:44-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=info msg="zeroconf server listening on port 33905" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="obtained new client token: AAC11UeGDY9aNoF+bqZ9QkJlIXrduJyZGo166e1kRZH3FOCFVfG96FNtmT6VM8ruMyp0EO1FSTZ9OgE1gkyUusUVB+I8o7KMHG+stPsuMxcHab/MzvyNNj251MftnnNjWSxQJYT7N4X5iua4yFW5nXLvaC4eGogB44oFE5LcvRsLi55Dkrs1EBu3lkyIVO0f7mAq5eTnJ3u8uHiXhNSBeizt47wfnQWKeiVywcumixs7npnTPlwos+sc/Q==" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=debug msg="completed challenge" Dec 12 08:49:45 kirwan-rivo go-librespot[6611]: time="2025-12-12T08:49:45-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:45 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:45 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:45 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:45 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:45 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:45 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:45.888] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:47 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioVolatilePlay Dec 12 08:49:47 kirwan-rivo volumio[3285]: info: CoreStateMachine::volatilePlay Dec 12 08:49:47 kirwan-rivo volumio[3285]: info: Received play: Dec 12 08:49:47 kirwan-rivo vtcs[3940]: [2025-12-12 08:49:47.115] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=4, playstate_=1, player_state_=0 Dec 12 08:49:47 kirwan-rivo volumio[3285]: info: Initializing connection to go-librespot Websocket Dec 12 08:49:47 kirwan-rivo volumio[3285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 08:49:48 kirwan-rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 12 08:49:48 kirwan-rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 379614. Dec 12 08:49:48 kirwan-rivo systemd[1]: Stopped go-librespot Daemon. Dec 12 08:49:48 kirwan-rivo systemd[1]: Started go-librespot Daemon. Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: go-librespot daemon starting... Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=info msg="running go-librespot 0.3.2" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=debug msg="app state loaded" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=debug msg="stored credentials not found" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=info msg="zeroconf server listening on port 37777" Dec 12 08:49:48 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:48-07:00" level=debug msg="obtained new client token: AAAXTsp9QdWex/b91S3AIkh7IW7kVxHouPWD+68LJszUoMSnMUpHCP2hhj7m65TiOBdePn9u2OEtxcNfpHfst8pAnyLZqY5zdM8ngr0vCm94kSXPx8FqP74x2dDJqvGsLooqKeQYq0bVtM09eDVuEWCx+YCnOLsIOvlPWztQOTvV2ruqE1LeJFsB39lGZHZahJn3MQcEO4J67VSpFqb1o/GBnrZ431FPzmMbd9eBYH9CTL1TcThYqeBkYzK7" Dec 12 08:49:49 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:49-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 12 08:49:49 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:49-07:00" level=debug msg="completed keyexchange" Dec 12 08:49:49 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:49-07:00" level=debug msg="completed challenge" Dec 12 08:49:49 kirwan-rivo go-librespot[6646]: time="2025-12-12T08:49:49-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 08:49:49 kirwan-rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 08:49:49 kirwan-rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 08:49:49 kirwan-rivo volumio[3285]: info: CoreCommandRouter::volumioRemoveQueueItem Dec 12 08:49:49 kirwan-rivo volumio[3285]: info: CoreStateMachine::removeQueueItem Dec 12 08:49:49 kirwan-rivo volumio[3285]: info: CoreStateMachine::stop Dec 12 08:49:49 kirwan-rivo volumio[3285]: info: CoreStateMachine::serviceStop Dec 12 08:49:49 kirwan-rivo volumio[3285]: info: CoreCommandRouter::serviceStop Dec 12 08:49:49 kirwan-rivo vtcs[3940]: [close:85] Entering Dec 12 08:49:49 kirwan-rivo vtcs[3940]: [close:100] Exiting Dec 12 08:49:49 kirwan-rivo volumio[3285]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 08:49:49 kirwan-rivo volumio[3285]: TypeError: Cannot read property 'then' of undefined Dec 12 08:49:49 kirwan-rivo volumio[3285]: at CoreStateMachine.removeQueueItem (/volumio/app/statemachine.js:1372:7) Dec 12 08:49:49 kirwan-rivo volumio[3285]: at CoreCommandRouter.volumioRemoveQueueItem (/volumio/app/index.js:121:28) Dec 12 08:49:49 kirwan-rivo volumio[3285]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:173:33) Dec 12 08:49:49 kirwan-rivo volumio[3285]: at Socket.emit (events.js:400:28) Dec 12 08:49:49 kirwan-rivo volumio[3285]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Dec 12 08:49:49 kirwan-rivo volumio[3285]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Dec 12 08:49:49 kirwan-rivo volumio[3285]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 08:49:50 kirwan-rivo sudo[6672]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-12 08:48 Dec 12 08:49:50 kirwan-rivo sudo[6672]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 08:04:08 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="bbdd85796562d864ebadb328c8f41ca1"