-- Logs begin at Tue 2025-06-24 15:30:07 -08, end at Tue 2025-06-24 15:53:29 -08. -- Jun 24 15:52:02 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:52:02 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:02 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 24 15:52:02 volumio volumio[8162]: (node:8162) 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: 75) Jun 24 15:52:02 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:52:02 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:52:02 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:02 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:52:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 299. Jun 24 15:52:02 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:52:02 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:52:02 volumio go-librespot[15822]: Librespot-go daemon starting... Jun 24 15:52:02 volumio go-librespot[15822]: time="2025-06-24T15:52:02-08:00" level=info msg="generated new device id: 42a66fffc0d1d2ddbd60cdb853e32358850d6b32" Jun 24 15:52:02 volumio go-librespot[15822]: time="2025-06-24T15:52:02-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:52:03 volumio go-librespot[15822]: time="2025-06-24T15:52:03-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:52:03 volumio go-librespot[15822]: time="2025-06-24T15:52:03-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:52:03 volumio go-librespot[15822]: time="2025-06-24T15:52:03-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:52:03 volumio go-librespot[15822]: time="2025-06-24T15:52:03-08:00" level=debug msg="zeroconf server listening on port 36347" Jun 24 15:52:05 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:05 volumio go-librespot[15822]: time="2025-06-24T15:52:05-08:00" level=debug msg="new websocket client" Jun 24 15:52:05 volumio volumio[8162]: info: Connection to go-librespot Websocket established Jun 24 15:52:08 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:52:08 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:52:08 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:52:27 volumio volumio[8162]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Jun 24 15:52:27 volumio volumio[8162]: info: Retrying Login Due to Network Error Jun 24 15:52:33 volumio go-librespot[15822]: time="2025-06-24T15:52:33-08:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" Jun 24 15:52:33 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 24 15:52:33 volumio volumio[8162]: at connResetException (internal/errors.js:639:14) Jun 24 15:52:33 volumio volumio[8162]: at Socket.socketOnEnd (_http_client.js:499:23) Jun 24 15:52:33 volumio volumio[8162]: at Socket.emit (events.js:412:35) Jun 24 15:52:33 volumio volumio[8162]: at endReadableNT (internal/streams/readable.js:1333:12) Jun 24 15:52:33 volumio volumio[8162]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jun 24 15:52:33 volumio volumio[8162]: (node:8162) 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: 76) Jun 24 15:52:33 volumio volumio[8162]: info: Connection to go-librespot Websocket closed Jun 24 15:52:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:52:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:52:36 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:36 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:52:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 300. Jun 24 15:52:36 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:52:36 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:52:36 volumio go-librespot[16062]: Librespot-go daemon starting... Jun 24 15:52:36 volumio go-librespot[16062]: time="2025-06-24T15:52:36-08:00" level=info msg="generated new device id: b9e385f559400d66c78b42a0bec84f2aa8d08ae2" Jun 24 15:52:36 volumio go-librespot[16062]: time="2025-06-24T15:52:36-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:52:37 volumio volumio[8162]: info: MyVolumio login type: Token Jun 24 15:52:37 volumio go-librespot[16062]: time="2025-06-24T15:52:37-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:52:37 volumio go-librespot[16062]: time="2025-06-24T15:52:37-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:52:37 volumio go-librespot[16062]: time="2025-06-24T15:52:37-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:52:37 volumio go-librespot[16062]: time="2025-06-24T15:52:37-08:00" level=debug msg="zeroconf server listening on port 40161" Jun 24 15:52:37 volumio go-librespot[16062]: time="2025-06-24T15:52:37-08:00" level=debug msg="obtained new client token: AABKSaGhVLYocRqtPXDyKIzPk4SgzbOcuD64zETgOSKvbXjcdxWu61sUIE+3dfbVHOVFtML0GaSdv0otCJAReF+e3jHBauUgsNo+aiJPIL8RMpVKMaGzrBtKbgtT+PGezLNkVXhFqb+lwshlYbVcLCRmb/EUts4RghSIJZG2QVFuuamkAd15BAFXlzCNltPph2KjsfcHchs1t0ruWep2HZO/6rGVszuLOwe3zTCWjgQ9jpE2lh3XhAeiWNdO" Jun 24 15:52:37 volumio go-librespot[16062]: time="2025-06-24T15:52:37-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:52:38 volumio go-librespot[16062]: time="2025-06-24T15:52:38-08:00" level=debug msg="completed keyexchange" Jun 24 15:52:38 volumio go-librespot[16062]: time="2025-06-24T15:52:38-08:00" level=debug msg="completed challenge" Jun 24 15:52:38 volumio go-librespot[16062]: time="2025-06-24T15:52:38-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:52:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:52:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:52:39 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:39 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:52:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 301. Jun 24 15:52:41 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:52:41 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:52:41 volumio go-librespot[16100]: Librespot-go daemon starting... Jun 24 15:52:41 volumio go-librespot[16100]: time="2025-06-24T15:52:41-08:00" level=info msg="generated new device id: d96fddfc2d73c1a2bff60e54419e254ee0878976" Jun 24 15:52:41 volumio go-librespot[16100]: time="2025-06-24T15:52:41-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:52:42 volumio go-librespot[16100]: time="2025-06-24T15:52:42-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:52:42 volumio go-librespot[16100]: time="2025-06-24T15:52:42-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:52:42 volumio go-librespot[16100]: time="2025-06-24T15:52:42-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:52:42 volumio go-librespot[16100]: time="2025-06-24T15:52:42-08:00" level=debug msg="zeroconf server listening on port 35267" Jun 24 15:52:42 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:42 volumio go-librespot[16100]: time="2025-06-24T15:52:42-08:00" level=debug msg="new websocket client" Jun 24 15:52:42 volumio volumio[8162]: info: Connection to go-librespot Websocket established Jun 24 15:52:43 volumio go-librespot[16100]: time="2025-06-24T15:52:43-08:00" level=debug msg="obtained new client token: AAB/77Eb3u/z4fjvJyOynh+fjj/eOJX1hLU8vLgBJUV5UOINipQyuRRr79KjGylXu6W+dFRqhsbRWOotX7gFmGQ09VRBkVd6/UO/UmzWtzl67wJe9D6OBdtu4n2ILsgLOolN+JRTTwqoWlxT8mNTgUFB1KK2TC/4vsuAdcv4ngL/laOTjEo7MdxByCb0QwQK4IhGan9yDTn4N7wDkDqLbZqKHWnHEt4LK/Et577AOB7YyHGBqhII/LBe3J9A" Jun 24 15:52:43 volumio go-librespot[16100]: time="2025-06-24T15:52:43-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:52:43 volumio go-librespot[16100]: time="2025-06-24T15:52:43-08:00" level=debug msg="completed keyexchange" Jun 24 15:52:43 volumio go-librespot[16100]: time="2025-06-24T15:52:43-08:00" level=debug msg="completed challenge" Jun 24 15:52:43 volumio go-librespot[16100]: time="2025-06-24T15:52:43-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:52:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:52:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:52:43 volumio volumio[8162]: info: Connection to go-librespot Websocket closed Jun 24 15:52:45 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:52:45 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:45 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 24 15:52:45 volumio volumio[8162]: (node:8162) 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: 77) Jun 24 15:52:45 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:52:45 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:52:46 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:46 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:52:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 302. Jun 24 15:52:47 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:52:47 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:52:47 volumio go-librespot[16155]: Librespot-go daemon starting... Jun 24 15:52:47 volumio go-librespot[16155]: time="2025-06-24T15:52:47-08:00" level=info msg="generated new device id: 8a88e581a4eaf6d687446562eae4a0585817add5" Jun 24 15:52:47 volumio go-librespot[16155]: time="2025-06-24T15:52:47-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=debug msg="zeroconf server listening on port 37203" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=debug msg="obtained new client token: AABG3ixGTVmGt5FrsstEpYb+yVbQ61R7Rewgnw3Mb4Vr9K7ESB+ORRwrja7DUYROrVfCYwfY1H7wfwiqtHV7U4XC5tcDLxuEceK71fVDu1NMu7vqAS+xmf0FhD22X0ic1xvn1RF9aYhM0AlF/8LKNJTaPBu8Hf8LjhtWCae7zPxhEn6Pgx3CCcWvEW125YkFpdZZUjPS7Yf/PjaVVTSTqWMrNKy8saIC7k9p7CXuOiiHgg8zZqZpAXmm8XOW" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070 (error: dial tcp 104.199.241.202:4070: connect: connection refused), retrying with a different AP" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=info msg="connected to ap-gae2.spotify.com:443" Jun 24 15:52:48 volumio go-librespot[16155]: time="2025-06-24T15:52:48-08:00" level=debug msg="completed keyexchange" Jun 24 15:52:49 volumio go-librespot[16155]: time="2025-06-24T15:52:49-08:00" level=debug msg="completed challenge" Jun 24 15:52:49 volumio go-librespot[16155]: time="2025-06-24T15:52:49-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:52:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:52:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:52:49 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:49 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:52:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 303. Jun 24 15:52:52 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:52:52 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:52:52 volumio go-librespot[16191]: Librespot-go daemon starting... Jun 24 15:52:52 volumio go-librespot[16191]: time="2025-06-24T15:52:52-08:00" level=info msg="generated new device id: 08b98fb1df2fed7b14a85e052fb831b0b8868078" Jun 24 15:52:52 volumio go-librespot[16191]: time="2025-06-24T15:52:52-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:52:52 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:52 volumio go-librespot[16191]: time="2025-06-24T15:52:52-08:00" level=debug msg="new websocket client" Jun 24 15:52:52 volumio volumio[8162]: info: Connection to go-librespot Websocket established Jun 24 15:52:53 volumio go-librespot[16191]: time="2025-06-24T15:52:53-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:52:53 volumio go-librespot[16191]: time="2025-06-24T15:52:53-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:52:53 volumio go-librespot[16191]: time="2025-06-24T15:52:53-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:52:53 volumio go-librespot[16191]: time="2025-06-24T15:52:53-08:00" level=debug msg="zeroconf server listening on port 45139" Jun 24 15:52:53 volumio go-librespot[16191]: time="2025-06-24T15:52:53-08:00" level=debug msg="obtained new client token: AAD06aprYsERwB4+82ULDQ3vI9us6TTQ41zhLXoFX4o3fRrb0kS1MDxe5qaY0lseSAM4fqY1/Y/t9T9hY8E7daXVJMpPSl88SKZIsKg9uI7qSXH3qSibq5xll1Sm+JxOHv6+j+Js54Xg0d6LTrccANkxbJLqLu4FZOGFAh5wUVfRAlvDxcDzLVxksrHBpWdJhePV/++Qet9+UuyE7qHPIQjzrfMONvIXAxVVKxbrMNa5dgwii9ndxMHUF805" Jun 24 15:52:53 volumio go-librespot[16191]: time="2025-06-24T15:52:53-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:52:54 volumio go-librespot[16191]: time="2025-06-24T15:52:54-08:00" level=debug msg="completed keyexchange" Jun 24 15:52:54 volumio go-librespot[16191]: time="2025-06-24T15:52:54-08:00" level=debug msg="completed challenge" Jun 24 15:52:54 volumio go-librespot[16191]: time="2025-06-24T15:52:54-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:52:54 volumio volumio[8162]: info: Connection to go-librespot Websocket closed Jun 24 15:52:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:52:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:52:55 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:52:55 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:55 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 24 15:52:55 volumio volumio[8162]: (node:8162) 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: 78) Jun 24 15:52:55 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:52:55 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:52:57 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:52:57 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:52:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:52:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304. Jun 24 15:52:57 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:52:57 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:52:57 volumio go-librespot[16243]: Librespot-go daemon starting... Jun 24 15:52:57 volumio go-librespot[16243]: time="2025-06-24T15:52:57-08:00" level=info msg="generated new device id: b7d63c074bcf35bd83bd2a6536fc6a7ff0666044" Jun 24 15:52:57 volumio go-librespot[16243]: time="2025-06-24T15:52:57-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:52:58 volumio go-librespot[16243]: time="2025-06-24T15:52:58-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 24 15:52:58 volumio go-librespot[16243]: time="2025-06-24T15:52:58-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 24 15:52:58 volumio go-librespot[16243]: time="2025-06-24T15:52:58-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 24 15:52:58 volumio go-librespot[16243]: time="2025-06-24T15:52:58-08:00" level=debug msg="zeroconf server listening on port 37471" Jun 24 15:52:59 volumio go-librespot[16243]: time="2025-06-24T15:52:59-08:00" level=debug msg="obtained new client token: AADU2mKKmgC76eZBbfrfIaX4Q5Y2N+FzLYQq1SGSYaKffOYOe95aCdOjEUxKbCVOqGNCm+2bsCBuWYrpiSrfi2+Zty/eba0RKKasMdIZYJZbnBcxtulQuCfVB61SyGZ7Zq5JWdlqeKEmevJ+8SkWyQa4a5qFZ1N1k+yxljaGz316OFlh03hUoPLBJeWDbBSnJ0lXwjyR7lSxYn8h1riAKmeosjdbjsl+H4LWfcWBc9ARdByiSAvRQmaGGw==" Jun 24 15:52:59 volumio go-librespot[16243]: time="2025-06-24T15:52:59-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:52:59 volumio go-librespot[16243]: time="2025-06-24T15:52:59-08:00" level=debug msg="completed keyexchange" Jun 24 15:52:59 volumio go-librespot[16243]: time="2025-06-24T15:52:59-08:00" level=debug msg="completed challenge" Jun 24 15:52:59 volumio go-librespot[16243]: time="2025-06-24T15:52:59-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:52:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:52:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:53:00 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:00 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:53:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 305. Jun 24 15:53:03 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:53:03 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:53:03 volumio go-librespot[16327]: Librespot-go daemon starting... Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=info msg="generated new device id: 15c10b4de0b2debcd45a9437e2423a30cb7b9f45" Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:53:03 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=debug msg="new websocket client" Jun 24 15:53:03 volumio volumio[8162]: info: Connection to go-librespot Websocket established Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 24 15:53:03 volumio go-librespot[16327]: time="2025-06-24T15:53:03-08:00" level=debug msg="zeroconf server listening on port 39795" Jun 24 15:53:04 volumio go-librespot[16327]: time="2025-06-24T15:53:04-08:00" level=debug msg="obtained new client token: AAAHQu7rcUBZsw7OOz6uF8+RCjsRgMZf6o2RYlQZB2u7Fk2JdB+2EzsL4V2cVtQAvt6GAFjiaMrXQzg4GQrTm55mswV+YF9/Oq43U8223rSDebuxW68ABCFPy4vKOjPyf1yQHpRjjE2iC4S5aoTdFIMsaceGRkC/L0NbRoE+g/bc7YV6tTX93+P9coj4cy5bPwN5QQ/bqTeHMALL1rfs/86AJSoXDaiGfQ0jNKyyh9I+H6EZJW2Qv/q/tQ==" Jun 24 15:53:04 volumio go-librespot[16327]: time="2025-06-24T15:53:04-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:53:04 volumio go-librespot[16327]: time="2025-06-24T15:53:04-08:00" level=debug msg="completed keyexchange" Jun 24 15:53:05 volumio go-librespot[16327]: time="2025-06-24T15:53:05-08:00" level=debug msg="completed challenge" Jun 24 15:53:05 volumio go-librespot[16327]: time="2025-06-24T15:53:05-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:53:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:53:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:53:05 volumio volumio[8162]: info: Connection to go-librespot Websocket closed Jun 24 15:53:06 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:53:06 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:06 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 24 15:53:06 volumio volumio[8162]: (node:8162) 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: 79) Jun 24 15:53:06 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:53:06 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:53:07 volumio volumio[8162]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Jun 24 15:53:07 volumio volumio[8162]: info: Retrying Login Due to Network Error Jun 24 15:53:08 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:08 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:53:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 306. Jun 24 15:53:08 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:53:08 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:53:08 volumio go-librespot[16381]: Librespot-go daemon starting... Jun 24 15:53:08 volumio go-librespot[16381]: time="2025-06-24T15:53:08-08:00" level=info msg="generated new device id: 575f7528b1c324adcb42f8ae3bd96700b69f3c61" Jun 24 15:53:08 volumio go-librespot[16381]: time="2025-06-24T15:53:08-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=debug msg="zeroconf server listening on port 45977" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=debug msg="obtained new client token: AACRKgRfPSFXI6kyuhDV9cUSjuBu0ndHnpjqlo5YzoOtbU/75v9/MxFPL/AqYKUQwIxMn01+tNODvYdJ8iWe6DmJC+EwdXxQ50uTPd+IohG7qaIMXheR8JwJS7pFn04IPOWP/L6IqCuE6yhpEKgdEA9KpPN+YLywTSs3FikZpInTZSxqwTX/JqqnVjYapvHVIvc+h5bpO2IS5xfkGIWw3VM0n8Nh2XjflfuUU7Ns98lZIFwlYebGHu2R7ku3" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:53:09 volumio go-librespot[16381]: time="2025-06-24T15:53:09-08:00" level=debug msg="completed keyexchange" Jun 24 15:53:10 volumio go-librespot[16381]: time="2025-06-24T15:53:10-08:00" level=debug msg="completed challenge" Jun 24 15:53:10 volumio go-librespot[16381]: time="2025-06-24T15:53:10-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:53:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:53:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:53:11 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:11 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:12 volumio ntpd[1022]: 5.79.108.34 local addr 192.168.0.125 -> Jun 24 15:53:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:53:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 307. Jun 24 15:53:13 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:53:13 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:53:13 volumio go-librespot[16415]: Librespot-go daemon starting... Jun 24 15:53:13 volumio go-librespot[16415]: time="2025-06-24T15:53:13-08:00" level=info msg="generated new device id: e0e3d42c603addc8ba665caac11349bb62b27692" Jun 24 15:53:13 volumio go-librespot[16415]: time="2025-06-24T15:53:13-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:53:14 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:14 volumio go-librespot[16415]: time="2025-06-24T15:53:14-08:00" level=debug msg="new websocket client" Jun 24 15:53:14 volumio volumio[8162]: info: Connection to go-librespot Websocket established Jun 24 15:53:15 volumio go-librespot[16415]: time="2025-06-24T15:53:15-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:53:15 volumio go-librespot[16415]: time="2025-06-24T15:53:15-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:53:15 volumio go-librespot[16415]: time="2025-06-24T15:53:15-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:53:15 volumio go-librespot[16415]: time="2025-06-24T15:53:15-08:00" level=debug msg="zeroconf server listening on port 33271" Jun 24 15:53:16 volumio go-librespot[16415]: time="2025-06-24T15:53:16-08:00" level=debug msg="obtained new client token: AAB7L6skp78c3t/1k3gux/wryYEkWzsOJ2cMd7pCxM5+NFKHJz0znxLQ7yESoVDIVN25gzYDGsRZlXRZJjP5YoNSamTX5A0rk6aF+Ae8Uv6ZnbXpvsDphV6LqLTyN7rY1pkJVFuk4pQjaX82at1FTNfmVSUQH6OgjvDLOjE8Z9yC/B8SR2PTWT7EZwgQCOHrLNL7H1JdPcBzMCteBJH0rNkGLTzsTIl94Of/YRXIEa0peCZBL4AZpggIiA==" Jun 24 15:53:16 volumio go-librespot[16415]: time="2025-06-24T15:53:16-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:53:16 volumio go-librespot[16415]: time="2025-06-24T15:53:16-08:00" level=debug msg="completed keyexchange" Jun 24 15:53:16 volumio go-librespot[16415]: time="2025-06-24T15:53:16-08:00" level=debug msg="completed challenge" Jun 24 15:53:16 volumio go-librespot[16415]: time="2025-06-24T15:53:16-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:53:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:53:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:53:16 volumio volumio[8162]: info: Connection to go-librespot Websocket closed Jun 24 15:53:17 volumio volumio[8162]: info: MyVolumio login type: Token Jun 24 15:53:17 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:53:17 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:17 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 24 15:53:17 volumio volumio[8162]: (node:8162) 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: 80) Jun 24 15:53:17 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:53:17 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:53:19 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:19 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:53:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 308. Jun 24 15:53:20 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:53:20 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:53:20 volumio go-librespot[16473]: Librespot-go daemon starting... Jun 24 15:53:20 volumio go-librespot[16473]: time="2025-06-24T15:53:20-08:00" level=info msg="generated new device id: 4745b24b4f21039e5504f389c696b1b7295c9e1a" Jun 24 15:53:20 volumio go-librespot[16473]: time="2025-06-24T15:53:20-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:53:20 volumio go-librespot[16473]: time="2025-06-24T15:53:20-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:53:20 volumio go-librespot[16473]: time="2025-06-24T15:53:20-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:53:20 volumio go-librespot[16473]: time="2025-06-24T15:53:20-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:53:20 volumio go-librespot[16473]: time="2025-06-24T15:53:20-08:00" level=debug msg="zeroconf server listening on port 34691" Jun 24 15:53:21 volumio go-librespot[16473]: time="2025-06-24T15:53:21-08:00" level=debug msg="obtained new client token: AAA7Ae+GNNZstBD1YWaZjQE1P16FaXNp4tweQrzuytw9XD6w4vvzYDMi7kMOhTIiFxI4LOzxXOkrRl/7I5Z+2F4e2r28FFtAI3GIPQjaPeGcOsYkfgMvcmpYvOe6VDgP/gOHUQhUX9yIhH01VYy/WWa+9ttY7yl04ME98maZWXPm1f2gkmWSJYbMfNlwDPaO4GQY9uoYypqQ9biPXU3aqRdHneFEEesnAXC0wKo6Jhzlps2QhbJ+yQCfgQ==" Jun 24 15:53:21 volumio go-librespot[16473]: time="2025-06-24T15:53:21-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:53:21 volumio go-librespot[16473]: time="2025-06-24T15:53:21-08:00" level=debug msg="completed keyexchange" Jun 24 15:53:21 volumio go-librespot[16473]: time="2025-06-24T15:53:21-08:00" level=debug msg="completed challenge" Jun 24 15:53:22 volumio go-librespot[16473]: time="2025-06-24T15:53:22-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:53:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:53:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:53:22 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:22 volumio volumio[8162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:24 volumio volumio[8162]: info: Jun 24 15:53:24 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:24 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:24 volumio volumio[8162]: info: Jun 24 15:53:24 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:24 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:24 volumio volumio[8162]: info: Jun 24 15:53:24 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:24 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:24 volumio volumio[8162]: info: sendMpdCommand status took 2 milliseconds Jun 24 15:53:24 volumio volumio[8162]: info: sendMpdCommand status took 1 milliseconds Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:24 volumio volumio[8162]: info: sendMpdCommand status took 2 milliseconds Jun 24 15:53:24 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 24 15:53:24 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:24 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:24 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:24 volumio volumio[8162]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":151601,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1154 Kbps","isStreaming":false,"title":"为什么你背着我爱别人","artist":"许志安","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/5298d92dc684d38b952dff31d06e2f8d/115266e9190dc5858d8574f2b50a23c8/115266e9190dc5858d8574f2b50a23c8_1298657955486373376_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235044Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=6c93a3149b8a6a3af0e9be39b5d2d43c5f7937ac341af2c0dcf0ed57f73f0a09","trackType":""} Jun 24 15:53:24 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::syncState stateService pause Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::stPlaybackTimer Jun 24 15:53:24 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:24 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:24 volumio volumio[8162]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":151601,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1154 Kbps","isStreaming":false,"title":"为什么你背着我爱别人","artist":"许志安","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/5298d92dc684d38b952dff31d06e2f8d/115266e9190dc5858d8574f2b50a23c8/115266e9190dc5858d8574f2b50a23c8_1298657955486373376_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235044Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=6c93a3149b8a6a3af0e9be39b5d2d43c5f7937ac341af2c0dcf0ed57f73f0a09","trackType":""} Jun 24 15:53:24 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::syncState stateService pause Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::stPlaybackTimer Jun 24 15:53:24 volumio volumio[8162]: info: ------------------------------ 14ms Jun 24 15:53:24 volumio volumio[8162]: info: ------------------------------ 15ms Jun 24 15:53:24 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 12 milliseconds Jun 24 15:53:24 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:24 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:24 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:24 volumio volumio[8162]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":151601,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1154 Kbps","isStreaming":false,"title":"为什么你背着我爱别人","artist":"许志安","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/5298d92dc684d38b952dff31d06e2f8d/115266e9190dc5858d8574f2b50a23c8/115266e9190dc5858d8574f2b50a23c8_1298657955486373376_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235044Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=6c93a3149b8a6a3af0e9be39b5d2d43c5f7937ac341af2c0dcf0ed57f73f0a09","trackType":""} Jun 24 15:53:24 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::syncState stateService pause Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:24 volumio volumio[8162]: info: CoreStateMachine::stPlaybackTimer Jun 24 15:53:24 volumio volumio[8162]: info: ------------------------------ 23ms Jun 24 15:53:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 24 15:53:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 309. Jun 24 15:53:25 volumio systemd[1]: Stopped go-librespot Daemon. Jun 24 15:53:25 volumio systemd[1]: Started go-librespot Daemon. Jun 24 15:53:25 volumio go-librespot[16530]: Librespot-go daemon starting... Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=info msg="generated new device id: 807575a7e7cecf54577134691ac49b086cdf9e70" Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=debug msg="stored credentials found for 31u4qduifkwexuitbvvikqwjwz5q" Jun 24 15:53:25 volumio volumio[8162]: info: Jun 24 15:53:25 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:25 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:25 volumio volumio[8162]: info: Jun 24 15:53:25 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:25 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:25 volumio volumio[8162]: info: Jun 24 15:53:25 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:25 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:25 volumio volumio[8162]: info: sendMpdCommand status took 2 milliseconds Jun 24 15:53:25 volumio volumio[8162]: info: sendMpdCommand status took 1 milliseconds Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:25 volumio volumio[8162]: info: sendMpdCommand status took 6 milliseconds Jun 24 15:53:25 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 24 15:53:25 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:25 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: CorePlayQueue::getTrack 0 Jun 24 15:53:25 volumio volumio[8162]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"为什么你背着我爱别人","artist":"许志安","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/5298d92dc684d38b952dff31d06e2f8d/115266e9190dc5858d8574f2b50a23c8/115266e9190dc5858d8574f2b50a23c8_1298657955486373376_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235044Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=6c93a3149b8a6a3af0e9be39b5d2d43c5f7937ac341af2c0dcf0ed57f73f0a09","trackType":""} Jun 24 15:53:25 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::syncState stateService stop Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::stPlaybackTimer Jun 24 15:53:25 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: CorePlayQueue::getTrack 0 Jun 24 15:53:25 volumio volumio[8162]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"为什么你背着我爱别人","artist":"许志安","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/5298d92dc684d38b952dff31d06e2f8d/115266e9190dc5858d8574f2b50a23c8/115266e9190dc5858d8574f2b50a23c8_1298657955486373376_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235044Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=6c93a3149b8a6a3af0e9be39b5d2d43c5f7937ac341af2c0dcf0ed57f73f0a09","trackType":""} Jun 24 15:53:25 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::syncState stateService stop Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus stop Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: No code Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: ------------------------------ 33ms Jun 24 15:53:25 volumio volumio[8162]: info: ------------------------------ 33ms Jun 24 15:53:25 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 27 milliseconds Jun 24 15:53:25 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:25 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: CorePlayQueue::getTrack 0 Jun 24 15:53:25 volumio volumio[8162]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"为什么你背着我爱别人","artist":"许志安","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/5298d92dc684d38b952dff31d06e2f8d/115266e9190dc5858d8574f2b50a23c8/115266e9190dc5858d8574f2b50a23c8_1298657955486373376_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235044Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=6c93a3149b8a6a3af0e9be39b5d2d43c5f7937ac341af2c0dcf0ed57f73f0a09","trackType":""} Jun 24 15:53:25 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::syncState stateService stop Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus stop Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: No code Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: ------------------------------ 54ms Jun 24 15:53:25 volumio volumio[8162]: info: Clearing queue after UPNP request Jun 24 15:53:25 volumio volumio[8162]: info: Initializing connection to go-librespot Websocket Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=debug msg="zeroconf server listening on port 39111" Jun 24 15:53:25 volumio go-librespot[16530]: time="2025-06-24T15:53:25-08:00" level=debug msg="new websocket client" Jun 24 15:53:25 volumio volumio[8162]: info: Connection to go-librespot Websocket established Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::ClearQueue Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::stop Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 24 15:53:25 volumio volumio[8162]: info: CorePlayQueue::clearPlayQueue Jun 24 15:53:25 volumio volumio[8162]: info: CorePlayQueue::saveQueue Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioPushQueue Jun 24 15:53:25 volumio volumio[8162]: info: Jun 24 15:53:25 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:25 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:25 volumio volumio[8162]: info: Jun 24 15:53:25 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:25 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:25 volumio volumio[8162]: info: Jun 24 15:53:25 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:25 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:25 volumio volumio[8162]: error: updateQueue error: null Jun 24 15:53:25 volumio volumio[8162]: error: updateQueue error: null Jun 24 15:53:25 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:25 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:25 volumio volumio[8162]: error: updateQueue error: null Jun 24 15:53:25 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:25 volumio volumio[8162]: info: Starting UPNP Playback Jun 24 15:53:25 volumio volumio[8162]: info: Preparing playback through UPNP Jun 24 15:53:25 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:53:25 volumio volumio[8162]: info: CorePlayQueue::getTrack 0 Jun 24 15:53:25 volumio volumio[8162]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 3ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 0ms Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 0ms Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 0ms Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 2ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 2ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 2ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: Jun 24 15:53:26 volumio volumio[8162]: ---------------------------- MPD announces system playlist update Jun 24 15:53:26 volumio volumio[8162]: info: Ignoring MPD Status Update Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 2ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio volumio[8162]: info: ------------------------------ 1ms Jun 24 15:53:26 volumio go-librespot[16530]: time="2025-06-24T15:53:26-08:00" level=debug msg="obtained new client token: AAC8d1JJ8NZpLHh3lvLfUqSs12+V4DMY2hulQrtc+9V58ettcRG7xPRPHRZP/lQfeVSSqU578l9j94gmEEC7qJsZLDa9wLZXlGo6i6tIcXiRkzPV8BD0VL1ZpdXwByOSYIG+5y808D5o0ujOdFCjqtrLw2m9KaYPHwjJEFq0WM6twM7joBdNOI5MfEKm7c5ngaDIe0oPoBYTC6Fy18GNPp7kp6pDWFZ7W86Ht2qx7LUuETIYso2bTnJaTlrS" Jun 24 15:53:26 volumio go-librespot[16530]: time="2025-06-24T15:53:26-08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jun 24 15:53:26 volumio go-librespot[16530]: time="2025-06-24T15:53:26-08:00" level=debug msg="completed keyexchange" Jun 24 15:53:27 volumio go-librespot[16530]: time="2025-06-24T15:53:27-08:00" level=debug msg="completed challenge" Jun 24 15:53:27 volumio go-librespot[16530]: time="2025-06-24T15:53:27-08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jun 24 15:53:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 24 15:53:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 24 15:53:27 volumio volumio[8162]: info: Connection to go-librespot Websocket closed Jun 24 15:53:27 volumio volumio[8162]: info: Jun 24 15:53:27 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:27 volumio volumio[8162]: info: Jun 24 15:53:27 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:27 volumio volumio[8162]: info: Jun 24 15:53:27 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:27 volumio volumio[8162]: info: Jun 24 15:53:27 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand status took 3 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand status took 4 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand status took 3 milliseconds Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:27 volumio volumio[8162]: info: Jun 24 15:53:27 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:27 volumio volumio[8162]: info: Jun 24 15:53:27 volumio volumio[8162]: ---------------------------- MPD announces state update: player Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::getState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand status Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand status took 3 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand status took 1 milliseconds Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:27 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:27 volumio volumio[8162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":302,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"吻别","artist":"张学友","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/757dbc3ff06b2a0f1ee41e15961a574e/00731451920820/HKA619900522_67153982-0f24-4d4b-9740-761ddc69f28b_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235054Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=dc2aafda0cc641dd243c58a3cdce38e0b2296b17df05989e79986ce2ba1aa614","trackType":""} Jun 24 15:53:27 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState stateService play Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus stop Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:27 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:27 volumio volumio[8162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":302,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"吻别","artist":"张学友","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/757dbc3ff06b2a0f1ee41e15961a574e/00731451920820/HKA619900522_67153982-0f24-4d4b-9740-761ddc69f28b_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235054Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=dc2aafda0cc641dd243c58a3cdce38e0b2296b17df05989e79986ce2ba1aa614","trackType":""} Jun 24 15:53:27 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState stateService play Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:27 volumio volumio[8162]: info: Received an update from plugin. extracting info from payload Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:27 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:27 volumio volumio[8162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":302,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"吻别","artist":"张学友","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/757dbc3ff06b2a0f1ee41e15961a574e/00731451920820/HKA619900522_67153982-0f24-4d4b-9740-761ddc69f28b_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235054Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=dc2aafda0cc641dd243c58a3cdce38e0b2296b17df05989e79986ce2ba1aa614","trackType":""} Jun 24 15:53:27 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState stateService play Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:27 volumio volumio[8162]: info: Received an update from plugin. extracting info from payload Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: ------------------------------ 18ms Jun 24 15:53:27 volumio volumio[8162]: info: ------------------------------ 30ms Jun 24 15:53:27 volumio volumio[8162]: info: ------------------------------ 30ms Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand status took 27 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 25 milliseconds Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 25 milliseconds Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseState Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:27 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:27 volumio volumio[8162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":302,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"吻别","artist":"张学友","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/757dbc3ff06b2a0f1ee41e15961a574e/00731451920820/HKA619900522_67153982-0f24-4d4b-9740-761ddc69f28b_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235054Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=dc2aafda0cc641dd243c58a3cdce38e0b2296b17df05989e79986ce2ba1aa614","trackType":""} Jun 24 15:53:27 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState stateService play Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:27 volumio volumio[8162]: info: Received an update from plugin. extracting info from payload Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:27 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:27 volumio volumio[8162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":302,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"吻别","artist":"张学友","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/757dbc3ff06b2a0f1ee41e15961a574e/00731451920820/HKA619900522_67153982-0f24-4d4b-9740-761ddc69f28b_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235054Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=dc2aafda0cc641dd243c58a3cdce38e0b2296b17df05989e79986ce2ba1aa614","trackType":""} Jun 24 15:53:27 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState stateService play Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:27 volumio volumio[8162]: info: Received an update from plugin. extracting info from payload Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: ------------------------------ 57ms Jun 24 15:53:27 volumio volumio[8162]: info: ------------------------------ 56ms Jun 24 15:53:27 volumio volumio[8162]: info: sendMpdCommand playlistinfo took 34 milliseconds Jun 24 15:53:27 volumio volumio[8162]: verbose: ControllerMpd::parseTrackInfo Jun 24 15:53:27 volumio volumio[8162]: info: ControllerMpd::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::servicePushState Jun 24 15:53:27 volumio volumio[8162]: verbose: In UPNP mode Jun 24 15:53:27 volumio volumio[8162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":302,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"吻别","artist":"张学友","album":null,"uri":"https://music-common-ucdn-drcn.dbankcdn.cn/757dbc3ff06b2a0f1ee41e15961a574e/00731451920820/HKA619900522_67153982-0f24-4d4b-9740-761ddc69f28b_1_SQ.flac?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=HPUA4SYAWHJ2ULRBCUO7%2F20250624%2Fcn-north-2%2Fs3%2Faws4_request&X-Amz-Date=20250624T235054Z&X-Amz-Expires=173000&X-Amz-SignedHeaders=host&X-Amz-Signature=dc2aafda0cc641dd243c58a3cdce38e0b2296b17df05989e79986ce2ba1aa614","trackType":""} Jun 24 15:53:27 volumio volumio[8162]: verbose: CURRENT POSITION 0 Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState stateService play Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::syncState currentStatus play Jun 24 15:53:27 volumio volumio[8162]: info: Received an update from plugin. extracting info from payload Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreStateMachine::pushState Jun 24 15:53:27 volumio volumio[8162]: info: CoreCommandRouter::volumioPushState Jun 24 15:53:27 volumio volumio[8162]: info: ------------------------------ 75ms Jun 24 15:53:28 volumio volumio[8162]: info: Getting Spotify volume Jun 24 15:53:28 volumio volumio[8162]: (node:8162) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 24 15:53:28 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 24 15:53:28 volumio volumio[8162]: (node:8162) 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: 81) Jun 24 15:53:28 volumio volumio[8162]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 15:53:28 volumio volumio[8162]: info: CoreCommandRouter::volumioGetState Jun 24 15:53:29 volumio volumio[8162]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 15:53:29 volumio volumio[8162]: Error: connect ETIMEDOUT 31.13.75.12:80 Jun 24 15:53:29 volumio volumio[8162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Jun 24 15:53:29 volumio volumio[8162]: errno: -110, Jun 24 15:53:29 volumio volumio[8162]: code: 'ETIMEDOUT', Jun 24 15:53:29 volumio volumio[8162]: syscall: 'connect', Jun 24 15:53:29 volumio volumio[8162]: address: '31.13.75.12', Jun 24 15:53:29 volumio volumio[8162]: port: 80 Jun 24 15:53:29 volumio volumio[8162]: } Jun 24 15:53:29 volumio volumio[8162]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 15:53:29 volumio sudo[16577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-24 15:52 Jun 24 15:53:29 volumio sudo[16577]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 05:26:48 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="a63f40325536655a08b14de2b295ce76"