-- Logs begin at Fri 2025-07-04 03:14:11 UTC, end at Fri 2025-07-04 04:30:39 UTC. --
Jul 04 04:29:00 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:00 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255774.
Jul 04 04:29:00 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:00 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:00 volumio go-librespot[24834]: Librespot-go daemon starting...
Jul 04 04:29:00 volumio go-librespot[24834]: time="2025-07-04T04:29:00Z" level=info msg="generated new device id: a87c1e408cdc20443ba52442e1b8a57ea9966556"
Jul 04 04:29:00 volumio go-librespot[24834]: time="2025-07-04T04:29:00Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:00 volumio go-librespot[24834]: time="2025-07-04T04:29:00Z" level=debug msg="obtained new client token: AAD6kXu1v7zB0SmkEgjFjsRk7lyDMXDmhTSPzGv9vNceI3e6xvXX+X8dbZZY2UCbCedMYOYsvt8etp4PX9Ev2XFcPmOeyT895Dq5vUsbnFUsoz2NFkspxeRRHdIhvXpkIGHkBU/YZSJv7Iz2VlN0S+zxUmLXSP+aSwQPZXq/TTzQYIFwETpo5XP29opHnPZVxd4LRIfEC0xu8MiQ8MAvk48fCS88KEPec7vMI3uQLE0nE0MHD/cvaUD2xDIiISU="
Jul 04 04:29:00 volumio go-librespot[24834]: time="2025-07-04T04:29:00Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:00 volumio go-librespot[24834]: time="2025-07-04T04:29:00Z" level=debug msg="completed keyexchange"
Jul 04 04:29:00 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:00 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:00 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:00 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:01 volumio go-librespot[24834]: time="2025-07-04T04:29:01Z" level=debug msg="completed challenge"
Jul 04 04:29:01 volumio go-librespot[24834]: time="2025-07-04T04:29:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:01 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:01 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:01 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:01 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:02 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:02 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:02 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:02 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:03 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:03 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:03 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:03 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:03 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:03 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255775.
Jul 04 04:29:04 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:04 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:04 volumio go-librespot[24842]: Librespot-go daemon starting...
Jul 04 04:29:04 volumio go-librespot[24842]: time="2025-07-04T04:29:04Z" level=info msg="generated new device id: 8f88fd4b4515892ac7ddb03a0c336337baf17e88"
Jul 04 04:29:04 volumio go-librespot[24842]: time="2025-07-04T04:29:04Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:04 volumio go-librespot[24842]: time="2025-07-04T04:29:04Z" level=debug msg="obtained new client token: AADLBeN29ssACgdqppl1BtHiFo9G7fbtyx+KrHqzWunWwCxPliL56XIEct+ksviCUk3ATK3tVh77LKMR9nVgAP7K3HZ4nY74OqUFkm9l4JusjIWCqJdcDEXWYFwwN+zrY4VLoCGyocjyEyAYJg/ie+ZFnEAv2D+c5F0OQzByS5s9wTikfHgH+YuCoJghegyLL6wEh8vu0tfcwa/TAc3ShyVSr0UNbQiKuikF5P3X1Ti17EB/6Ue6Lk7lzGTRMM0="
Jul 04 04:29:04 volumio go-librespot[24842]: time="2025-07-04T04:29:04Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:04 volumio go-librespot[24842]: time="2025-07-04T04:29:04Z" level=debug msg="completed keyexchange"
Jul 04 04:29:04 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:04 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:04 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:04 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:05 volumio go-librespot[24842]: time="2025-07-04T04:29:05Z" level=debug msg="completed challenge"
Jul 04 04:29:05 volumio go-librespot[24842]: time="2025-07-04T04:29:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:05 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:05 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:05 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:05 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:06 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:06 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:06 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:06 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:06 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:06 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:07 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:07 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:07 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:07 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255776.
Jul 04 04:29:08 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:08 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:08 volumio go-librespot[24867]: Librespot-go daemon starting...
Jul 04 04:29:08 volumio go-librespot[24867]: time="2025-07-04T04:29:08Z" level=info msg="generated new device id: 3e8dd4b05dc2b911302532e16023379292d0071e"
Jul 04 04:29:08 volumio go-librespot[24867]: time="2025-07-04T04:29:08Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:08 volumio go-librespot[24867]: time="2025-07-04T04:29:08Z" level=debug msg="obtained new client token: AADD1ShvE30u13PDIitfcBy5KpJFDS5taYDMATFkPWzLfl8bIDUwrukCcyy+LskujK6RsdPpPLHMNqrfLUCHIb9rm92NB96CuG73Ts/hJdLWlCqjzObbCqyNYXrp1nPegncs/7vf5gk23K8dRkHyCY1S83C/lIbCbcWkqVFc3B9n9LEpAYTLdCgc9jdzeaEwsjbUN9gGUPJG+n4ajAofrIMRwEe+3yhHs8kHcr6ubE9Y19zHt6yACw614wakgmY="
Jul 04 04:29:08 volumio go-librespot[24867]: time="2025-07-04T04:29:08Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:08 volumio go-librespot[24867]: time="2025-07-04T04:29:08Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused"
Jul 04 04:29:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:08 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:08 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:08 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:08 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:09 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:09 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:09 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:09 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:09 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:09 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:10 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:10 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:10 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:10 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255777.
Jul 04 04:29:11 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:11 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:11 volumio go-librespot[24876]: Librespot-go daemon starting...
Jul 04 04:29:11 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:11 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:11 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:11 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:11 volumio go-librespot[24876]: time="2025-07-04T04:29:11Z" level=info msg="generated new device id: 65868103a7bfc6fc44a89b93860dbfb45ba87295"
Jul 04 04:29:11 volumio go-librespot[24876]: time="2025-07-04T04:29:11Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:11 volumio go-librespot[24876]: time="2025-07-04T04:29:11Z" level=debug msg="obtained new client token: AADZDbnSuodT8Hoospz+K7A4nbRr2G4T/erQ0+MDeqkJ0rMT3zgW5NBJNO6qtLpRmEu7UAcF1DgH6EKP3DWEj7eyYidT/VKUM8cC0zwOid3h7zivDS3+/9LOs4IjM8m4R971g0fq2RsCB+CEkFWnP/xXrc595q9tJRxaHTfGB0j/n6aunXpzjJZhyLMkzyPH48yVEBopAQ9W7tdhkuq117aGMhgIQkr0H7YBLkz016oi9NQfjESqKpSIuXTBKGM="
Jul 04 04:29:12 volumio go-librespot[24876]: time="2025-07-04T04:29:12Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:12 volumio go-librespot[24876]: time="2025-07-04T04:29:12Z" level=debug msg="completed keyexchange"
Jul 04 04:29:12 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:12 volumio go-librespot[24876]: time="2025-07-04T04:29:12Z" level=debug msg="new websocket client"
Jul 04 04:29:12 volumio volumio[910]: info: Connection to go-librespot Websocket established
Jul 04 04:29:12 volumio go-librespot[24876]: time="2025-07-04T04:29:12Z" level=debug msg="completed challenge"
Jul 04 04:29:12 volumio go-librespot[24876]: time="2025-07-04T04:29:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:12 volumio volumio[910]: info: Connection to go-librespot Websocket closed
Jul 04 04:29:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:12 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:12 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:12 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:12 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:13 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:13 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:13 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:13 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:14 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:14 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:14 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:14 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:15 volumio volumio[910]: info: Getting Spotify volume
Jul 04 04:29:15 volumio volumio[910]: (node:910) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:15 volumio volumio[910]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 04 04:29:15 volumio volumio[910]: (node:910) 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: 27937)
Jul 04 04:29:15 volumio volumio[910]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Jul 04 04:29:15 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:15 volumio volumio[910]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 04 04:29:15 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:15 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255778.
Jul 04 04:29:15 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:15 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:15 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:15 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:15 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:15 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:15 volumio go-librespot[24898]: Librespot-go daemon starting...
Jul 04 04:29:15 volumio go-librespot[24898]: time="2025-07-04T04:29:15Z" level=info msg="generated new device id: 02fad8975c7abb0ec788bf70424eeabb4de22280"
Jul 04 04:29:15 volumio go-librespot[24898]: time="2025-07-04T04:29:15Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:16 volumio go-librespot[24898]: time="2025-07-04T04:29:16Z" level=debug msg="obtained new client token: AAAzjNxbqR+MJVaPMhF5mu4U+kJ1mor2i8wQZpF9sHVqMywp80NlSlUJSrki7G6zJnmGRMN7CojJ8dWhEcFffap+T52pimJhoakOKMPRLUiDY/hVdE4SY1dTYDonVg0lxfGXI1w1tZxM1S1WnZ/luurWsHDUUUCuBBvppZwoC4xDgVWZOvuWX9XY4k1GJ53zmlB72iXDqBX7t8OYZ/3iWAdRlkqTJP9PvdqVybgh248LrBEKcywG/iB8t1jW+wY="
Jul 04 04:29:16 volumio go-librespot[24898]: time="2025-07-04T04:29:16Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:16 volumio go-librespot[24898]: time="2025-07-04T04:29:16Z" level=debug msg="completed keyexchange"
Jul 04 04:29:16 volumio go-librespot[24898]: time="2025-07-04T04:29:16Z" level=debug msg="completed challenge"
Jul 04 04:29:16 volumio go-librespot[24898]: time="2025-07-04T04:29:16Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:16 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:16 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:16 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:16 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:17 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:17 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:17 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:17 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:18 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:18 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:18 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:18 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:18 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:18 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255779.
Jul 04 04:29:19 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:19 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:19 volumio go-librespot[24906]: Librespot-go daemon starting...
Jul 04 04:29:19 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:19 volumio go-librespot[24906]: time="2025-07-04T04:29:19Z" level=info msg="generated new device id: dde6eda37bcc0332ef7355c8009e08855b0efce4"
Jul 04 04:29:19 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:19 volumio go-librespot[24906]: time="2025-07-04T04:29:19Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:19 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:19 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:20 volumio go-librespot[24906]: time="2025-07-04T04:29:20Z" level=debug msg="obtained new client token: AAC/2OfusCFD7a5ialsRW0KV6RO6UA6XduUDFNKYe+cFtZQzPvknhKMnWyFFxD/TcKGVVDmZTiixIji3k+wAqmf57sg7pQwIYfwoPb8PyG3JFgmtCnVO6oadxQc1zE02VxViqWs43n8o+zlSDw+GlAbaon7No83Fg0InUI/jsgayBn7G69OtIvh007lzDeWre4xXd5aDDobJAmjHpgdwgegy3Pt0ZvTX73VzK6TOFVfQw9x9KQ54TneljVvB"
Jul 04 04:29:20 volumio go-librespot[24906]: time="2025-07-04T04:29:20Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:20 volumio go-librespot[24906]: time="2025-07-04T04:29:20Z" level=debug msg="completed keyexchange"
Jul 04 04:29:20 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:20 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:20 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:20 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:20 volumio go-librespot[24906]: time="2025-07-04T04:29:20Z" level=debug msg="completed challenge"
Jul 04 04:29:20 volumio go-librespot[24906]: time="2025-07-04T04:29:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:21 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:21 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:21 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:21 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:21 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:21 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:22 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:22 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:22 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:22 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:23 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:23 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:23 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:23 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255780.
Jul 04 04:29:24 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:24 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:24 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:24 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:24 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:24 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:24 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:24 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:25 volumio go-librespot[24952]: Librespot-go daemon starting...
Jul 04 04:29:25 volumio go-librespot[24952]: time="2025-07-04T04:29:25Z" level=info msg="generated new device id: 983f35e4a0754d74ebc5e283a08bff4bb5694197"
Jul 04 04:29:25 volumio go-librespot[24952]: time="2025-07-04T04:29:25Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:25 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:25 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:25 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:25 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:26 volumio go-librespot[24952]: time="2025-07-04T04:29:26Z" level=debug msg="obtained new client token: AACvy4eamRsqigMXBRC3KIADTr1nNHWNkPZXP79r/VUaU5qlfbVVD3GrZcNYnfJ7lSFdrmEfBNbmkBLY1UK+EI3Ho3vs6p/9h7wTT7rraTQD67S5pE3WAD8b/1zyKCCWAk7d/sXQgo24lKCjfR8Rg1xOoxRrmgtJlx4GRtg8cU7EeZpg0oUKPCOuW6CcMZMXJTWtrpTpf/yiAIbyWCRq09WDXItJOWhRoAofAihBnOl0YI3yJQ7fKQeJ7aKPzlg="
Jul 04 04:29:26 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:26 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:26 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:26 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:27 volumio go-librespot[24952]: time="2025-07-04T04:29:27Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:27 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:27 volumio go-librespot[24952]: time="2025-07-04T04:29:27Z" level=debug msg="new websocket client"
Jul 04 04:29:27 volumio volumio[910]: info: Connection to go-librespot Websocket established
Jul 04 04:29:27 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:27 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:27 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:27 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:28 volumio go-librespot[24952]: time="2025-07-04T04:29:28Z" level=debug msg="completed keyexchange"
Jul 04 04:29:28 volumio go-librespot[24952]: time="2025-07-04T04:29:28Z" level=debug msg="completed challenge"
Jul 04 04:29:28 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:28 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:28 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:28 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:29 volumio go-librespot[24952]: time="2025-07-04T04:29:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:29 volumio volumio[910]: info: Connection to go-librespot Websocket closed
Jul 04 04:29:29 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:29 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:29 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:29 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:30 volumio volumio[910]: info: Getting Spotify volume
Jul 04 04:29:30 volumio volumio[910]: (node:910) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:30 volumio volumio[910]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 04 04:29:30 volumio volumio[910]: (node:910) 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: 27938)
Jul 04 04:29:30 volumio volumio[910]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Jul 04 04:29:30 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:30 volumio volumio[910]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 04 04:29:30 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:30 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:30 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:30 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:31 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:31 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:31 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:31 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:32 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:32 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255781.
Jul 04 04:29:32 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:32 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:32 volumio go-librespot[24979]: Librespot-go daemon starting...
Jul 04 04:29:32 volumio go-librespot[24979]: time="2025-07-04T04:29:32Z" level=info msg="generated new device id: 4b7f7c37f0b328db0322fd6bdf79a1f7809270d4"
Jul 04 04:29:32 volumio go-librespot[24979]: time="2025-07-04T04:29:32Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:32 volumio go-librespot[24979]: time="2025-07-04T04:29:32Z" level=debug msg="obtained new client token: AACyyAkbIwUtfDkv1vSGtHumVXbr+KPKdQFBXgDtRICFC7r5hbGtEmf6pzJkgUqi98piZ74G+iQx3AYv2rK7guUvUlSRQp4Ua4B653c0gA0/8AhYFluVdRNcRoB4ZQmqdCxzNAbjh1NXtihljkal3B0X+g9TnLTXoFoGffXMP4UQdgMvttJAXClpCa9XvgLSdayiANz+EwGHA7oYNvQTzq0j9RjxW+ZTMhGZaIZpu+bg2iwpvcdlx2YG0UBO97Y="
Jul 04 04:29:32 volumio go-librespot[24979]: time="2025-07-04T04:29:32Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Jul 04 04:29:32 volumio go-librespot[24979]: time="2025-07-04T04:29:32Z" level=debug msg="completed keyexchange"
Jul 04 04:29:32 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:32 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:32 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:32 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:33 volumio go-librespot[24979]: time="2025-07-04T04:29:33Z" level=debug msg="completed challenge"
Jul 04 04:29:33 volumio go-librespot[24979]: time="2025-07-04T04:29:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:33 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:33 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:33 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:33 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:34 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:34 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:34 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:34 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:35 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:35 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:35 volumio volumio-remote-updater[605]: zsync done
Jul 04 04:29:35 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:35 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:35 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:35 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255782.
Jul 04 04:29:36 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:36 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:36 volumio go-librespot[24992]: Librespot-go daemon starting...
Jul 04 04:29:36 volumio go-librespot[24992]: time="2025-07-04T04:29:36Z" level=info msg="generated new device id: 0bc548fde7624f29de6b1cec073d65fc8c20d327"
Jul 04 04:29:36 volumio go-librespot[24992]: time="2025-07-04T04:29:36Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:36 volumio go-librespot[24992]: time="2025-07-04T04:29:36Z" level=debug msg="obtained new client token: AADxou3aElMDo5cWLRsyRkwzR561ENPZ3ARZJcrm6KcaIZbYppiZhS6t0Jp7NlU/IHtZo3RnlO4TVB6Ra/aYJHD4OdR6q5RozjYC154eaaLtJhpmAby3NeWe6ueh60PUmQmYgDheM+7k1z6EZwsyDSLRczq7OmCzlVlDyt3toW+ECCr7Ny7Hd3ZjsdzszUHv6NZhIG4mT23EB1Crsbavx82k83V8R9p6xq4eyM6WR+/sxTBZ1vavT7XcVlBO3A4="
Jul 04 04:29:36 volumio go-librespot[24992]: time="2025-07-04T04:29:36Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:36 volumio go-librespot[24992]: time="2025-07-04T04:29:36Z" level=debug msg="completed keyexchange"
Jul 04 04:29:36 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:36 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:36 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:36 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:37 volumio go-librespot[24992]: time="2025-07-04T04:29:37Z" level=debug msg="completed challenge"
Jul 04 04:29:37 volumio go-librespot[24992]: time="2025-07-04T04:29:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:37 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:37 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:37 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:37 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:38 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:38 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:38 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:38 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:38 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:38 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:39 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:39 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:39 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:39 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255783.
Jul 04 04:29:40 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:40 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:40 volumio go-librespot[25014]: Librespot-go daemon starting...
Jul 04 04:29:40 volumio go-librespot[25014]: time="2025-07-04T04:29:40Z" level=info msg="generated new device id: 543e5eb84a58a15e01a84ec2c9ba2d0c1a6bd294"
Jul 04 04:29:40 volumio go-librespot[25014]: time="2025-07-04T04:29:40Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:40 volumio go-librespot[25014]: time="2025-07-04T04:29:40Z" level=debug msg="obtained new client token: AABhMJzzLnYHgMU8p0rT1dnBsKGI8G5Hv1ueJ1XvqCT/a+N6zAepSTZSc4ndiA2xVTW3qGOSDhdBXv+JCc3nZpXHn9s35GX61E52cvrJ6mrDLPOG9b0kDbrMXHncFGCuWD5LgrAcfD0Fu3X/gLAF8qzA1Scm2bE6E0vthAHZmaXp9GQSRc8FJw8eJgfrp7SGRK3J8yrzG3YC4700uQko5aJd9JiYkDFNc4R9AHnGP6c6IDRzICVCi2iYI2ddAok="
Jul 04 04:29:40 volumio go-librespot[25014]: time="2025-07-04T04:29:40Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:40 volumio go-librespot[25014]: time="2025-07-04T04:29:40Z" level=debug msg="completed keyexchange"
Jul 04 04:29:40 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:40 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:40 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:40 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:41 volumio go-librespot[25014]: time="2025-07-04T04:29:41Z" level=debug msg="completed challenge"
Jul 04 04:29:41 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:41 volumio go-librespot[25014]: time="2025-07-04T04:29:41Z" level=debug msg="new websocket client"
Jul 04 04:29:41 volumio volumio[910]: info: Connection to go-librespot Websocket established
Jul 04 04:29:41 volumio go-librespot[25014]: time="2025-07-04T04:29:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:41 volumio volumio[910]: info: Connection to go-librespot Websocket closed
Jul 04 04:29:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:41 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:41 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:41 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:41 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:42 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:42 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:42 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:42 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:43 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:43 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:43 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:43 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:44 volumio volumio[910]: info: Getting Spotify volume
Jul 04 04:29:44 volumio volumio[910]: (node:910) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:44 volumio volumio[910]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 04 04:29:44 volumio volumio[910]: (node:910) 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: 27939)
Jul 04 04:29:44 volumio volumio[910]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Jul 04 04:29:44 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:44 volumio volumio[910]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 04 04:29:44 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:44 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255784.
Jul 04 04:29:44 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:44 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:44 volumio go-librespot[25022]: Librespot-go daemon starting...
Jul 04 04:29:44 volumio go-librespot[25022]: time="2025-07-04T04:29:44Z" level=info msg="generated new device id: 02cb3c6fefb6086b9ea41fc7564449ca310db1ea"
Jul 04 04:29:44 volumio go-librespot[25022]: time="2025-07-04T04:29:44Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:44 volumio go-librespot[25022]: time="2025-07-04T04:29:44Z" level=debug msg="obtained new client token: AAAb4PNAfZYg2lGSTDtLM97zYDLsRZwzePdrGDNfO+YIcAMMiaHYLqUD5ZJxLgivwfMC3efizik+i4L6bkzdYx8EhNTRsRcP72gc11SKLePkyc56+aOLHeuiFi229psIgFGbOxG9ew6Fc8iqAOBdCrN/1H2hf8n6ygPEj1ijC19t3ouYjN7vSaFYT1EuNRChxL/5out1uwxpMID2n+r5s49WlXtiU1f4FDfmvbuwv1fJW/7fOUk0L6AkGB+Kczo="
Jul 04 04:29:44 volumio go-librespot[25022]: time="2025-07-04T04:29:44Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:44 volumio go-librespot[25022]: time="2025-07-04T04:29:44Z" level=debug msg="completed keyexchange"
Jul 04 04:29:44 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:44 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:44 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:44 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:45 volumio volumio-remote-updater[605]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 04 04:29:45 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:29:45 volumio volumio[910]: updateProgress
Jul 04 04:29:45 volumio volumio[910]: {
Jul 04 04:29:45 volumio volumio[910]: downloadSpeed: '',
Jul 04 04:29:45 volumio volumio[910]: eta: '2m',
Jul 04 04:29:45 volumio volumio[910]: progress: 80,
Jul 04 04:29:45 volumio volumio[910]: status: 'Downloading new update'
Jul 04 04:29:45 volumio volumio[910]: }
Jul 04 04:29:45 volumio go-librespot[25022]: time="2025-07-04T04:29:45Z" level=debug msg="completed challenge"
Jul 04 04:29:45 volumio go-librespot[25022]: time="2025-07-04T04:29:45Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:45 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:45 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jul 04 04:29:45 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:45 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:45 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:46 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:46 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:46 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:46 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:47 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:47 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:47 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:47 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:47 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:47 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255785.
Jul 04 04:29:48 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:48 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:48 volumio go-librespot[25052]: Librespot-go daemon starting...
Jul 04 04:29:48 volumio go-librespot[25052]: time="2025-07-04T04:29:48Z" level=info msg="generated new device id: 713a788632875f959a644c7fa720d92319d2c545"
Jul 04 04:29:48 volumio go-librespot[25052]: time="2025-07-04T04:29:48Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:48 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:48 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:48 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:48 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:49 volumio go-librespot[25052]: time="2025-07-04T04:29:49Z" level=debug msg="obtained new client token: AADHpRVytxpCYdg5DTSvOFffLDJWe5TUDyMr5nk3QjXhYr07B6sO+dge/V00kvSzxZSCpAgeTOdjLzIiS7MDbxhJgh1eJfdpNQM+uCJn9KadvWSBZVIlf9HjEJV7JpUadd6v+hfjoTo977xiP4TWmru+8uBiqeGxhwqh3eA9T0XAh5AKtAgWSvvIax8UnrwmmGYwvpaC6ZiZ8dEUZak7gU16j2FEtpNU7YJMH0LIteSpkMpBYyuch/4OQbnlqWQ="
Jul 04 04:29:49 volumio go-librespot[25052]: time="2025-07-04T04:29:49Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:29:49 volumio go-librespot[25052]: time="2025-07-04T04:29:49Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused"
Jul 04 04:29:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:49 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:49 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:49 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:49 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:50 volumio kernel: hwmon hwmon1: Voltage normalised
Jul 04 04:29:50 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:50 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:29:50 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:50 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:50 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:50 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:51 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:51 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:51 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:51 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:52 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:52 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:52 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:52 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:29:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255786.
Jul 04 04:29:53 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:29:53 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:29:53 volumio go-librespot[25062]: Librespot-go daemon starting...
Jul 04 04:29:53 volumio go-librespot[25062]: time="2025-07-04T04:29:53Z" level=info msg="generated new device id: 1b7a5108249fafa593c0ffd950f60fca88016c45"
Jul 04 04:29:53 volumio go-librespot[25062]: time="2025-07-04T04:29:53Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:29:53 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:29:53 volumio go-librespot[25062]: time="2025-07-04T04:29:53Z" level=debug msg="new websocket client"
Jul 04 04:29:53 volumio volumio[910]: info: Connection to go-librespot Websocket established
Jul 04 04:29:53 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:53 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:53 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:53 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:54 volumio go-librespot[25062]: time="2025-07-04T04:29:54Z" level=debug msg="obtained new client token: AAD9cwBH2cjjoly+TODmniynBdTpQVy34Pbw0dZzmgZFh+jJlVYsOqFkSJUXdK+Hf/O1abJWAMSs36x2cxQ/WEAqjht7oIh6coAo9Y1tQSNIczszX8hkF5fIw92FvLuWD9XkATp1iAN5/hPkZwpWNtshyAjCCrjUyEzPVuDLHdc/lO5CUAatIlmT2bay2AHyZf3DHbx+UqTwYsMXVhKizOgqbuS6txgNQQeurVCvNa5QCvWs37Q+UPzp86nr"
Jul 04 04:29:54 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:54 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:54 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:54 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:55 volumio go-librespot[25062]: time="2025-07-04T04:29:55Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Jul 04 04:29:55 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:55 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:55 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:55 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:56 volumio volumio[910]: info: Getting Spotify volume
Jul 04 04:29:56 volumio volumio[910]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Jul 04 04:29:56 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:56 volumio volumio[910]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 04 04:29:56 volumio go-librespot[25062]: time="2025-07-04T04:29:56Z" level=debug msg="completed keyexchange"
Jul 04 04:29:56 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:56 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:56 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:56 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:57 volumio go-librespot[25062]: time="2025-07-04T04:29:57Z" level=debug msg="completed challenge"
Jul 04 04:29:57 volumio volumio-remote-updater[605]: zsync done
Jul 04 04:29:57 volumio go-librespot[25062]: time="2025-07-04T04:29:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:29:57 volumio volumio[910]: (node:910) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 04 04:29:57 volumio volumio[910]: at connResetException (internal/errors.js:607:14)
Jul 04 04:29:57 volumio volumio[910]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 04 04:29:57 volumio volumio[910]: at Socket.emit (events.js:327:22)
Jul 04 04:29:57 volumio volumio[910]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 04 04:29:57 volumio volumio[910]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 04 04:29:57 volumio volumio[910]: (node:910) 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: 27940)
Jul 04 04:29:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:29:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:29:57 volumio volumio[910]: info: Connection to go-librespot Websocket closed
Jul 04 04:29:57 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:57 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:57 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:57 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:58 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:58 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:58 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:58 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:29:59 volumio volumio-remote-updater[605]: PROGRESS: 90, STATUS: "Cleaning old files", ETA: "1m"
Jul 04 04:29:59 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:29:59 volumio volumio[910]: updateProgress
Jul 04 04:29:59 volumio volumio[910]: {
Jul 04 04:29:59 volumio volumio[910]: downloadSpeed: '',
Jul 04 04:29:59 volumio volumio[910]: eta: '1m',
Jul 04 04:29:59 volumio volumio[910]: progress: 90,
Jul 04 04:29:59 volumio volumio[910]: status: 'Cleaning old files'
Jul 04 04:29:59 volumio volumio[910]: }
Jul 04 04:29:59 volumio volumio-remote-updater[605]: /bin/cp: cannot stat '/data/volumio_factory.sqsh': No such file or directory
Jul 04 04:29:59 volumio volumio-remote-updater[605]: /bin/rm: cannot remove '/data/volumio_factory.sqsh': No such file or directory
Jul 04 04:29:59 volumio volumio-remote-updater[605]: PROGRESS: 95, STATUS: "Finalizing update", ETA: "30s"
Jul 04 04:29:59 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:29:59 volumio volumio[910]: updateProgress
Jul 04 04:29:59 volumio volumio[910]: {
Jul 04 04:29:59 volumio volumio[910]: downloadSpeed: '',
Jul 04 04:29:59 volumio volumio[910]: eta: '30s',
Jul 04 04:29:59 volumio volumio[910]: progress: 95,
Jul 04 04:29:59 volumio volumio[910]: status: 'Finalizing update'
Jul 04 04:29:59 volumio volumio[910]: }
Jul 04 04:29:59 volumio volumio-remote-updater[605]: PROGRESS: 100, STATUS: "success", MESSAGE: "Successfully updated to \"3.819\" version. System restart required."
Jul 04 04:29:59 volumio volumio-remote-updater[605]: No test mode
Jul 04 04:29:59 volumio volumio-remote-updater[605]: No alpha test mode
Jul 04 04:29:59 volumio volumio-remote-updater[605]: [2025-07-04 04:29:59] [disconnect] Disconnect close local:[1000] remote:[1000]
Jul 04 04:29:59 volumio volumio-remote-updater[605]: [2025-07-04 04:29:59] [info] asio async_write error: system:32 (Broken pipe)
Jul 04 04:29:59 volumio volumio-remote-updater[605]: [2025-07-04 04:29:59] [fatal] handle_write_frame error: websocketpp.transport:2 (Underlying Transport Error)
Jul 04 04:29:59 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:29:59 volumio volumio[910]: updateReady
Jul 04 04:29:59 volumio volumio[910]: {
Jul 04 04:29:59 volumio volumio[910]: changeLogLink: 'http://volumio.org',
Jul 04 04:29:59 volumio volumio[910]: description: 'FIXES
\n' +
Jul 04 04:29:59 volumio volumio[910]: '\n' +
Jul 04 04:29:59 volumio volumio[910]: '- Disable UI controls during DLNA playback
\n' +
Jul 04 04:29:59 volumio volumio[910]: '- Fix for Cast functionality halting due to memory filling up
\n' +
Jul 04 04:29:59 volumio volumio[910]: '- Fix for XML parsing on web-radio search
\n' +
Jul 04 04:29:59 volumio volumio[910]: '
\n' +
Jul 04 04:29:59 volumio volumio[910]: 'NEW ADDITIONS
\n' +
Jul 04 04:29:59 volumio volumio[910]: '\n' +
Jul 04 04:29:59 volumio volumio[910]: '- Add link for downloading CORRD in the side-menu
\n' +
Jul 04 04:29:59 volumio volumio[910]: '
\n',
Jul 04 04:29:59 volumio volumio[910]: title: 'Update v3.819',
Jul 04 04:29:59 volumio volumio[910]: updateavailable: true
Jul 04 04:29:59 volumio volumio[910]: }
Jul 04 04:29:59 volumio systemd[1]: volumio-remote-updater.service: Succeeded.
Jul 04 04:29:59 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:29:59 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:29:59 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:29:59 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:00 volumio systemd[1]: volumio-remote-updater.service: Service RestartSec=100ms expired, scheduling restart.
Jul 04 04:30:00 volumio systemd[1]: volumio-remote-updater.service: Scheduled restart job, restart counter is at 1.
Jul 04 04:30:00 volumio systemd[1]: Stopped volumio-remote-updater.service.
Jul 04 04:30:00 volumio systemd[1]: Started volumio-remote-updater.service.
Jul 04 04:30:00 volumio volumio-remote-updater[25101]: Error: No active session
Jul 04 04:30:00 volumio volumio-remote-updater[25101]: [2025-07-04 04:30:00] [connect] Successful connection
Jul 04 04:30:00 volumio volumio-remote-updater[25101]: [2025-07-04 04:30:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1751603400 101
Jul 04 04:30:00 volumio volumio[910]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 5
Jul 04 04:30:00 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:30:00 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:30:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255787.
Jul 04 04:30:00 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:00 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:00 volumio go-librespot[25104]: Librespot-go daemon starting...
Jul 04 04:30:00 volumio go-librespot[25104]: time="2025-07-04T04:30:00Z" level=info msg="generated new device id: 16dd8c6e683bb0e7c974d9ba5e56342ab60edc67"
Jul 04 04:30:00 volumio go-librespot[25104]: time="2025-07-04T04:30:00Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:00 volumio go-librespot[25104]: time="2025-07-04T04:30:00Z" level=debug msg="obtained new client token: AACIQ4Kgppi1IbwUpg6XQCMQNw/W1fR94bUpUFWpNcnarZQiuNu0mrY/KLN4mcFkEPMLXKHMhz1/gFgQIViyZMNAegqPCnZSfFiK9OJ5osUDtd0956d/X2l1aJVpYUaYf5mE5J0NNrpDmCYXZ6vLj0WiaxtCynbPP+d2/CClIrgQUwZC3zqUQo2jJMZigRhw3qAFae+cjtp1ahSs/CKeVFkIPBThoSrkKkwKOKP01Bes+ZUqY4SJ7DdWhTbYwl0="
Jul 04 04:30:00 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:00 volumio go-librespot[25104]: time="2025-07-04T04:30:00Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:00 volumio go-librespot[25104]: time="2025-07-04T04:30:00Z" level=debug msg="completed keyexchange"
Jul 04 04:30:00 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:00 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:00 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:00 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:01 volumio go-librespot[25104]: time="2025-07-04T04:30:01Z" level=debug msg="completed challenge"
Jul 04 04:30:01 volumio go-librespot[25104]: time="2025-07-04T04:30:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:01 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:01 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:01 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:01 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:01 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:02 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:02 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:02 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:02 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:02 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:03 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:30:03 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:30:03 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:03 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:03 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:03 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:03 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255788.
Jul 04 04:30:04 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:04 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:04 volumio go-librespot[25112]: Librespot-go daemon starting...
Jul 04 04:30:04 volumio go-librespot[25112]: time="2025-07-04T04:30:04Z" level=info msg="generated new device id: d9c63fdb0d162a0a352eb3f9629c4b445d83862b"
Jul 04 04:30:04 volumio go-librespot[25112]: time="2025-07-04T04:30:04Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:04 volumio go-librespot[25112]: time="2025-07-04T04:30:04Z" level=debug msg="obtained new client token: AADb6QwmWjN8LIR4whVFz3Cv6JlmoO/JtA6355vQU/wfqvUE8UpopzxKGgSwM0qeHuH69DtS8ifclcyQ8JMNmso6ruadqsvU2cu/RPBsN8R8G0PnPGDNCaqyXEsJaXC2FK7ftZc+L0dL441QSmeqZ9Rv38GEJQpqpAlDCeNriA67FITUcfTpp0cjHnfAwg8NP/x1WEckj0aU3U8WQnLk9S8vArEs5vZMZSJcROZJaK5ZkOrxLKvl2LBu6dN8vDM="
Jul 04 04:30:04 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:04 volumio go-librespot[25112]: time="2025-07-04T04:30:04Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:04 volumio go-librespot[25112]: time="2025-07-04T04:30:04Z" level=debug msg="completed keyexchange"
Jul 04 04:30:04 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:04 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:04 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:04 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:05 volumio go-librespot[25112]: time="2025-07-04T04:30:05Z" level=debug msg="completed challenge"
Jul 04 04:30:05 volumio go-librespot[25112]: time="2025-07-04T04:30:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:05 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:05 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:05 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:05 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:05 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:06 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:30:06 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:30:06 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:06 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:06 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:06 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:06 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:07 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:07 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:07 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:07 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:07 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255789.
Jul 04 04:30:08 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:08 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:08 volumio go-librespot[25137]: Librespot-go daemon starting...
Jul 04 04:30:08 volumio go-librespot[25137]: time="2025-07-04T04:30:08Z" level=info msg="generated new device id: db724d2ef5edfaa67b6e50024669f35c67458684"
Jul 04 04:30:08 volumio go-librespot[25137]: time="2025-07-04T04:30:08Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:08 volumio go-librespot[25137]: time="2025-07-04T04:30:08Z" level=debug msg="obtained new client token: AAC2D7h4qLU/PSC+L4LTDib1GnFAShw0ODJTDjrLpHjfLtL94oXLrfX9/m1WQjYEcxF09T4wBPekmZ6pnwJgiX5hy4NUKJumWpDHeyCWhhzUaHFJX/dpc4GgQstrWO9Vqom0defa9Cy+bpaBILbntUvcG7d7y03Jp/PEaLKV/o8dVc9ZPwJP3eJJWClBrcseumeQ3tIovrmgpX/56lb9oiWll3d65UId6cio9CZl9kNztr8icDPeI+MFkADwLpU="
Jul 04 04:30:08 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:08 volumio go-librespot[25137]: time="2025-07-04T04:30:08Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:08 volumio go-librespot[25137]: time="2025-07-04T04:30:08Z" level=debug msg="completed keyexchange"
Jul 04 04:30:08 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:08 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:08 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:08 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:09 volumio go-librespot[25137]: time="2025-07-04T04:30:09Z" level=debug msg="completed challenge"
Jul 04 04:30:09 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:30:09 volumio go-librespot[25137]: time="2025-07-04T04:30:09Z" level=debug msg="new websocket client"
Jul 04 04:30:09 volumio volumio[910]: info: Connection to go-librespot Websocket established
Jul 04 04:30:09 volumio go-librespot[25137]: time="2025-07-04T04:30:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:09 volumio volumio[910]: info: Connection to go-librespot Websocket closed
Jul 04 04:30:09 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:09 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:09 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:09 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:09 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:10 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:10 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:10 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:10 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:10 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:11 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:11 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:11 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:11 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:11 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:12 volumio volumio[910]: info: Getting Spotify volume
Jul 04 04:30:12 volumio volumio[910]: (node:910) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:30:12 volumio volumio[910]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 04 04:30:12 volumio volumio[910]: (node:910) 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: 27941)
Jul 04 04:30:12 volumio volumio[910]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6
Jul 04 04:30:12 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:30:12 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:30:12 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:12 volumio volumio[910]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 04 04:30:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255790.
Jul 04 04:30:12 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:12 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:12 volumio go-librespot[25146]: Librespot-go daemon starting...
Jul 04 04:30:12 volumio go-librespot[25146]: time="2025-07-04T04:30:12Z" level=info msg="generated new device id: 05f3a7db7fbeab9686981c83dae548d9fbbd5353"
Jul 04 04:30:12 volumio go-librespot[25146]: time="2025-07-04T04:30:12Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:12 volumio go-librespot[25146]: time="2025-07-04T04:30:12Z" level=debug msg="obtained new client token: AACoYnsjloLInb2k7MGk8ESlLWbofrA36VBuixktY+toTlh2VcVWxPTnS5Fzrp8KzeBLkeQX/0dz2xOsDZjTg+uGf+I28ryrxBD2OwBiljETx4O2qrLrNWNBPIhFRM3rXzZ4cL1/tRwXwlwG+KA+vUWqQVYXtcwh5v2+HEuQIYzirnvn42cbK/3h5v/wCSQFj5BXiNr6vTBlf77kmkzftfV2zyyGg9YUqzkVXO9q7Wnci6uzx7V9DPHrG5hceKc="
Jul 04 04:30:12 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:12 volumio go-librespot[25146]: time="2025-07-04T04:30:12Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:12 volumio go-librespot[25146]: time="2025-07-04T04:30:12Z" level=debug msg="completed keyexchange"
Jul 04 04:30:12 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:12 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:12 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:12 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:13 volumio go-librespot[25146]: time="2025-07-04T04:30:13Z" level=debug msg="completed challenge"
Jul 04 04:30:13 volumio go-librespot[25146]: time="2025-07-04T04:30:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:13 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:13 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:13 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:13 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:13 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:14 volumio volumio[910]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 04 04:30:14 volumio volumio[910]: info: CoreCommandRouter::volumioGetState
Jul 04 04:30:14 volumio volumio[910]: info: CoreCommandRouter::volumioGetQueue
Jul 04 04:30:14 volumio volumio[910]: info: CoreStateMachine::getQueue
Jul 04 04:30:14 volumio volumio[910]: info: CorePlayQueue::getQueue
Jul 04 04:30:15 volumio volumio[910]: info: Initializing connection to go-librespot Websocket
Jul 04 04:30:15 volumio volumio[910]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 04 04:30:15 volumio volumio[910]: info: CoreCommandRouter::Close All Modals sent
Jul 04 04:30:15 volumio volumio[910]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________
Jul 04 04:30:15 volumio volumio[910]: info: PLUGIN onReboot : networkfs
Jul 04 04:30:15 volumio sudo[25155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/DSD_MUSIC
Jul 04 04:30:15 volumio sudo[25155]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 04 04:30:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255791.
Jul 04 04:30:16 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:16 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:16 volumio go-librespot[25166]: Librespot-go daemon starting...
Jul 04 04:30:16 volumio go-librespot[25166]: time="2025-07-04T04:30:16Z" level=info msg="generated new device id: 0fd5da17e4bf3a80c85a324eef72237d20f5fc79"
Jul 04 04:30:16 volumio go-librespot[25166]: time="2025-07-04T04:30:16Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:16 volumio go-librespot[25166]: time="2025-07-04T04:30:16Z" level=debug msg="obtained new client token: AAB4OmEzVStcLPTJ3y/L1qTWyaIbq9nqzdH6apJpHcxo70W081DGoTHdql69vbjL3DFB7xJQ4m/7Mp6ELq+/aPkG1aMn6I/a8vJAjYuvfSMILQwY9RdcebhbcE4YsYXMtLXe5W5vmH4yHSwsrxCwzPCJF//G36OmbsiW16JgHQGtqtNQdvymu4flm/sw90DCbuH5YGa6b/ancOTv15VljPMMk3OOOG0gZz3jp/CNxdzFQXoLUv55OMuhJkbhfN0="
Jul 04 04:30:16 volumio go-librespot[25166]: time="2025-07-04T04:30:16Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:16 volumio go-librespot[25166]: time="2025-07-04T04:30:16Z" level=debug msg="completed keyexchange"
Jul 04 04:30:17 volumio go-librespot[25166]: time="2025-07-04T04:30:17Z" level=debug msg="completed challenge"
Jul 04 04:30:17 volumio go-librespot[25166]: time="2025-07-04T04:30:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255792.
Jul 04 04:30:20 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:20 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:20 volumio go-librespot[25180]: Librespot-go daemon starting...
Jul 04 04:30:20 volumio go-librespot[25180]: time="2025-07-04T04:30:20Z" level=info msg="generated new device id: 99f77b327ca60fbaff8a6af03af363fdf5fbec01"
Jul 04 04:30:20 volumio go-librespot[25180]: time="2025-07-04T04:30:20Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:20 volumio go-librespot[25180]: time="2025-07-04T04:30:20Z" level=debug msg="obtained new client token: AABmmOsCiyXnd8dUoGAs5PRQK5PI8AFzA4XJvldz3I43kYGkWOplPr+Yo6c4418Zd0wX+XC0tgazCGSy4OfjeMHlceUQA4e2EYJi2lyiqxAy2t5hez7uE1C++1oVkNzu8RBmgfm+opvXj7/bCLfxHexLTTVUMSBu8fO784pz2krLfh8HJLmTy6TbXTZZUOwdV4F7mjte5DYdZQ3wDw6sLg/HEKaKGYy38Yixfa5jW6HMcz0A2fvt5Rp+CLTi768="
Jul 04 04:30:20 volumio go-librespot[25180]: time="2025-07-04T04:30:20Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:20 volumio go-librespot[25180]: time="2025-07-04T04:30:20Z" level=debug msg="completed keyexchange"
Jul 04 04:30:21 volumio go-librespot[25180]: time="2025-07-04T04:30:21Z" level=debug msg="completed challenge"
Jul 04 04:30:21 volumio go-librespot[25180]: time="2025-07-04T04:30:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255793.
Jul 04 04:30:24 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:24 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:24 volumio go-librespot[25226]: Librespot-go daemon starting...
Jul 04 04:30:24 volumio go-librespot[25226]: time="2025-07-04T04:30:24Z" level=info msg="generated new device id: eba5f68a955f6522e5ead3fc56c11633dd56427e"
Jul 04 04:30:24 volumio go-librespot[25226]: time="2025-07-04T04:30:24Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:24 volumio go-librespot[25226]: time="2025-07-04T04:30:24Z" level=debug msg="obtained new client token: AAAeqWF1M10uWKdQ6bGfDZ3l2CPLPjK9YBLtQ0i/O7Sn1BX7vE6vBRueuoloh2oDSy0VVF2IlRNfsjkffC9Kf20NtC7JH3gFY7sKgk4BIr3w06Ner2OMimdgl7GT5Kxv1z12O/0rkOTQC2+SuLn8qmUiCif3+pFKqvp84zFYmXOvoA0RCKdUhFlgPkTBYi7xWZStqKsjSZEY2DSVMe4GF+8Een5bAPVo8j4uIDJhVdYbkuq+KRgX0TvHDRrmMzw="
Jul 04 04:30:24 volumio go-librespot[25226]: time="2025-07-04T04:30:24Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:24 volumio go-librespot[25226]: time="2025-07-04T04:30:24Z" level=debug msg="completed keyexchange"
Jul 04 04:30:25 volumio go-librespot[25226]: time="2025-07-04T04:30:25Z" level=debug msg="completed challenge"
Jul 04 04:30:25 volumio go-librespot[25226]: time="2025-07-04T04:30:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:25 volumio volumio[910]: error: Cannot umount share DSD_MUSIC : Error: spawnSync /bin/sh ETIMEDOUT
Jul 04 04:30:25 volumio sudo[25235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Leftovers
Jul 04 04:30:25 volumio sudo[25235]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 04 04:30:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255794.
Jul 04 04:30:28 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:28 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:28 volumio go-librespot[25255]: Librespot-go daemon starting...
Jul 04 04:30:28 volumio go-librespot[25255]: time="2025-07-04T04:30:28Z" level=info msg="generated new device id: 3b90a896c5d9e8ad2dfa43e811234be3d5a275ac"
Jul 04 04:30:28 volumio go-librespot[25255]: time="2025-07-04T04:30:28Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:28 volumio go-librespot[25255]: time="2025-07-04T04:30:28Z" level=debug msg="obtained new client token: AAAw3IZ5sfOPLuX/j4cIXz2WsZRJ2WymNRr1x3Y6cb5c4DQxA0YIO47GjQRE0PfTc5yWhAVo7EkHzfKXpjXQaNqvLP12ZeXhMrLJjzEJzepJItH0oEj4LMTRbik8xN+2jQF4HBkJuBPkTIv3QB+sdol9kWQ7JNMIB+V3TeZt0a7idPFBc0kgZZgpSLNN6FjWXGO1hVAxR0Xp3OfauJqbMJrs5ZkGQCJ/A5MEdZk0Hqsm3K7Hly/ATpIno2dYTLo="
Jul 04 04:30:28 volumio go-librespot[25255]: time="2025-07-04T04:30:28Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:28 volumio go-librespot[25255]: time="2025-07-04T04:30:28Z" level=debug msg="completed keyexchange"
Jul 04 04:30:28 volumio systemd[1]: mnt-NAS-Leftovers.mount: Succeeded.
Jul 04 04:30:28 volumio sudo[25235]: pam_unix(sudo:session): session closed for user root
Jul 04 04:30:28 volumio sudo[25264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Music
Jul 04 04:30:28 volumio sudo[25264]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 04 04:30:28 volumio systemd[1]: mnt-NAS-DSD_MUSIC.mount: Succeeded.
Jul 04 04:30:29 volumio sudo[25155]: pam_unix(sudo:session): session closed for user root
Jul 04 04:30:29 volumio go-librespot[25255]: time="2025-07-04T04:30:29Z" level=debug msg="completed challenge"
Jul 04 04:30:29 volumio go-librespot[25255]: time="2025-07-04T04:30:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:30 volumio volumio-remote-updater[25101]: [2025-07-04 04:30:30] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006]
Jul 04 04:30:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255795.
Jul 04 04:30:32 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:32 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:32 volumio go-librespot[25271]: Librespot-go daemon starting...
Jul 04 04:30:32 volumio go-librespot[25271]: time="2025-07-04T04:30:32Z" level=info msg="generated new device id: ac6016c3a9057ae0b597a55762840f54dba48cfc"
Jul 04 04:30:32 volumio go-librespot[25271]: time="2025-07-04T04:30:32Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:32 volumio go-librespot[25271]: time="2025-07-04T04:30:32Z" level=debug msg="obtained new client token: AACpUYOciDhhCZIkZGK8LNjy/QEeMf/v9J8o6Bya/ejVNy+l8J5KZKpPhYmi5wIrR+vqUNg7GV3gLCdm9lJ6765sdrDfPQhSVgBqhFDawCVlSWr11PIdLuEolKDjrooHm15mUB9OiFMPTsKUYQe9zeL9kNR/1PNNvepYc6wi1wTmacbs0siXJ1WHW3XRrqj0Dk8KBXYX7qShIZqJklJf4ILGGlJqYGFflGc9m1PxHg1ZEljvED0+kkV33DZO6n8="
Jul 04 04:30:32 volumio go-librespot[25271]: time="2025-07-04T04:30:32Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:32 volumio go-librespot[25271]: time="2025-07-04T04:30:32Z" level=debug msg="completed keyexchange"
Jul 04 04:30:33 volumio go-librespot[25271]: time="2025-07-04T04:30:33Z" level=debug msg="completed challenge"
Jul 04 04:30:33 volumio go-librespot[25271]: time="2025-07-04T04:30:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:35 volumio volumio-remote-updater[25101]: [2025-07-04 04:30:35] [connect] Successful connection
Jul 04 04:30:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 04 04:30:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255796.
Jul 04 04:30:36 volumio systemd[1]: Stopped go-librespot Daemon.
Jul 04 04:30:36 volumio systemd[1]: Started go-librespot Daemon.
Jul 04 04:30:36 volumio go-librespot[25279]: Librespot-go daemon starting...
Jul 04 04:30:36 volumio go-librespot[25279]: time="2025-07-04T04:30:36Z" level=info msg="generated new device id: 34a1d83206a9ba7e5774f7f4c096f8cec807af4c"
Jul 04 04:30:36 volumio go-librespot[25279]: time="2025-07-04T04:30:36Z" level=debug msg="stored credentials found for adonzell"
Jul 04 04:30:36 volumio go-librespot[25279]: time="2025-07-04T04:30:36Z" level=debug msg="obtained new client token: AABUdpTvkZxg6J0BO9BGhzOBR8vsrdha1AAf9z9gb/TwBvtlFXz2LZmyMAHZyluCD0DOxKvAIXR2xdFrghcBXEoiusP52sgkQhcsWJTV9HDORlzYCub35WkubIFLPdRlg/A+ujXE0nGcz4dE/3FKCQAUrHd2xfLQCx+9YKP9za43yPZanRwqC3INpx3XM748idGlCJbFISTS4OZ+iZsw0gv6dLXYmTXGgZh8hX1fhhXGaQrMoLeeHKGDLD1MPf8="
Jul 04 04:30:36 volumio go-librespot[25279]: time="2025-07-04T04:30:36Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 04 04:30:36 volumio go-librespot[25279]: time="2025-07-04T04:30:36Z" level=debug msg="completed keyexchange"
Jul 04 04:30:37 volumio go-librespot[25279]: time="2025-07-04T04:30:37Z" level=debug msg="completed challenge"
Jul 04 04:30:37 volumio go-librespot[25279]: time="2025-07-04T04:30:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 04 04:30:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 04 04:30:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 04 04:30:38 volumio volumio[910]: error: Cannot umount share Music : Error: spawnSync /bin/sh ETIMEDOUT
Jul 04 04:30:38 volumio volumio[910]: info: PLUGIN onReboot : audiophonicsonoff
Jul 04 04:30:38 volumio volumio[910]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 04 04:30:38 volumio volumio[910]: TypeError: Cannot read property 'writeSync' of undefined
Jul 04 04:30:38 volumio volumio[910]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25)
Jul 04 04:30:38 volumio volumio[910]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30)
Jul 04 04:30:38 volumio volumio[910]: at HashMap. (/volumio/app/pluginmanager.js:668:31)
Jul 04 04:30:38 volumio volumio[910]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Jul 04 04:30:38 volumio volumio[910]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Jul 04 04:30:38 volumio volumio[910]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20)
Jul 04 04:30:38 volumio volumio[910]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22)
Jul 04 04:30:38 volumio volumio[910]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/updater_comm/index.js:156:35)
Jul 04 04:30:38 volumio volumio[910]: at listOnTimeout (internal/timers.js:554:17)
Jul 04 04:30:38 volumio volumio[910]: at processTimers (internal/timers.js:497:7)
Jul 04 04:30:38 volumio volumio[910]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 04 04:30:39 volumio sudo[25310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-04 04:29
Jul 04 04:30:39 volumio sudo[25310]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST"
VOLUMIO_VERSION="3.816"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"